[pgsql-jp: 42031] Re: PostgreSQL11にてPROCEDUREを使用したPL/pgSQLでメモリ増加
misakana ＠ yahoo.co.jp
misakana ＠ yahoo.co.jp
2019年 9月 19日 (木) 02:25:05 UTC
永吉です。
高塚様、笠原様。現象の確認ありがとうございます。
PostgreSQL12beta3での確認を行いたかったのですが、
時間がなくて出来ていませんでした。再現するのですね！
FUNCTIONを使用すると、メモリ増加が起きない事は、
こちらでも確認しています。何か回避策を考えてみます。
新しい情報がありましたら、連絡のほどよろしくお願いします。
--- kasahara.tatsuhito ＠ gmail.com wrote:
> 笠原と申します。
>
> PostgreSQL12beta3のCentOS環境で再現しますね。ある程度ProcedureがCALLされた時点でgdbで止めて
> p MemoryContextStats(TopMemoryContext) でメモリ状態をログに吐き出させたところ、以下のように
> プロシージャ単位のメモリ保存場所に、CALL回数にほぼ比例したキャッシュが溜まっていました。
> 内容はPlanなどのCache(ただし領域だけで中身はない)に見えます。
> リークっぽいとは思いますが、Procedureの中で再度Procedureが大量にCALLされてしまうと
> 今時点ではこうなってしまうようです。
> どこまで有効かはわかりませんが・・Procedureの中で CALL Procedureではなく
> SELECT Functionで呼び出すようにすれば、処理内容次第ですがメモリの使い過ぎは
> 避けられるかもしれません。
> # 手元の簡単な再現では大丈夫でした
>
> TopMemoryContext: 80776 total in 6 blocks; 6976 free (10 chunks); 73800 used
> TopTransactionContext: 8192 total in 1 blocks; 7504 free (1 chunks); 688 used
> ExecutorState: 8192 total in 1 blocks; 3344 free (2 chunks); 4848 used
> ExprContext: 8192 total in 1 blocks; 7936 free (0 chunks); 256 used
> PLpgSQL cast info: 8192 total in 1 blocks; 7936 free (0 chunks); 256 used
> PLpgSQL cast cache: 8192 total in 1 blocks; 1584 free (0 chunks); 6608 used
> PL/pgSQL function: 8192 total in 1 blocks; 4968 free (3 chunks);
> 3224 used: p_dps11z()
> PL/pgSQL function: 92274688 total in 21 blocks; 3342320 free (17
> chunks); 88932368 used: pc_dps11e(integer) ★
> CFuncHash: 8192 total in 1 blocks; 560 free (0 chunks); 7632 used
> Rendezvous variable hash: 8192 total in 1 blocks; 560 free (0
> chunks); 7632 used
> PLpgSQL function hash: 24528 total in 2 blocks; 2624 free (0
> chunks); 21904 used
> RowDescriptionContext: 8192 total in 1 blocks; 6896 free (0 chunks); 1296 used
> MessageContext: 8192 total in 1 blocks; 3864 free (1 chunks); 4328 used
> Operator class cache: 8192 total in 1 blocks; 560 free (0 chunks); 7632 used
> smgr relation table: 32768 total in 3 blocks; 16832 free (8 chunks);
> 15936 used
> TransactionAbortContext: 32768 total in 1 blocks; 32512 free (0
> chunks); 256 used
> Portal hash: 8192 total in 1 blocks; 560 free (0 chunks); 7632 used
> TopPortalContext: 8192 total in 1 blocks; 7664 free (0 chunks); 528 used
> PortalContext: 1024 total in 1 blocks; 392 free (0 chunks); 632 used:
> SPI Proc: 131072 total in 5 blocks; 10000 free (0 chunks); 121072 used
> CachedPlan: 1024 total in 1 blocks; 80 free (0 chunks); 944
> used: CALL p_dps11z()
> CachedPlanSource: 1024 total in 1 blocks; 144 free (0 chunks);
> 880 used: CALL p_dps11z()
> CachedPlanQuery: 2048 total in 2 blocks; 936 free (1
> chunks); 1112 used
> (繰り返し・・)
> SPI Plan: 1024 total in 1 blocks; 608 free (0 chunks); 416 used
> CachedPlan: 1024 total in 1 blocks; 80 free (0 chunks); 944
> used: CALL p_dps11z()
> 14902 more child contexts containing 25446400 total in 24836
> blocks; 8796248 free (4967 chunks); 16650152 used ★
> ExecutorState: 8192 total in 1 blocks; 5920 free (0 chunks); 2272 used
> ExprContext: 8192 total in 1 blocks; 7936 free (0 chunks); 256 used
> Relcache by OID: 16384 total in 2 blocks; 3512 free (2 chunks); 12872 used
> CacheMemoryContext: 1048576 total in 8 blocks; 477824 free (3
> chunks); 570752 used
> CachedPlan: 2048 total in 2 blocks; 392 free (0 chunks); 1656
> used: SELECT pg_sleep(10.0)
> CachedPlanSource: 2048 total in 2 blocks; 304 free (0 chunks);
> 1744 used: SELECT pg_sleep(10.0)
> (略)
> WAL record construction: 49768 total in 2 blocks; 6368 free (0
> chunks); 43400 used
> PrivateRefCount: 8192 total in 1 blocks; 2624 free (0 chunks); 5568 used
> MdSmgr: 8192 total in 1 blocks; 6952 free (0 chunks); 1240 used
> LOCALLOCK hash: 8192 total in 1 blocks; 560 free (0 chunks); 7632 used
> Timezones: 104120 total in 2 blocks; 2624 free (0 chunks); 101496 used
> ErrorContext: 8192 total in 1 blocks; 7936 free (5 chunks); 256 used
> Grand total: 119764088 bytes in 25245 blocks; 12907720 free (5135
> chunks); 106856368 used
>
> 2019年9月13日(金) 10:11 TAKATSUKA Haruka <harukat ＠ postgresql.jp>:
> >
> > 永吉さん、
> > 高塚と申します。
> >
> > Linux で調べると、ループが続く限りプロセスの使用メモリが増え続ける
> > というわけでも無いですね。
> > ただ、一時的にプロセスの使用メモリ量が大きく膨らむ動作は観測できました。
> > あまり詳しく調べていないのですが、ひとまず報告しておきます。
> >
> > db1=# CREATE TABLE t1 (id int, v text);
> > db1=# INSERT INTO t1 SELECT g, md5(g::text) FROM generate_series(1, 100000) g;
> > db1=# CREATE PROCEDURE pc_sub() LANGUAGE plpgsql AS $$ DECLARE rec RECORD;
> > BEGIN SELECT * INTO rec FROM t1; NULL; END; $$;
> > db1=# CREATE PROCEDURE pc_main(c int) LANGUAGE plpgsql AS $$ DECLARE n int;
> > BEGIN FOR n IN 1 .. c LOOP CALL pc_sub(); END LOOP; END $$;
> > db1=# CALL pc_main(1000000);
> >
> > [postgres ~]$ ps x | grep CALL | grep -v grep
> > 16867 ? Ds 1:22 postgres: postgres db1 [local] CALL
> > [postgres ~]$ p=16867 ; echo -n "PID:$p mem use(kB):" ; \
> > cat /proc/$p/smaps | grep Private | sed -e 's/^.*://' -e 's/kB//' | \
> > awk '{ sum += $1 } ; END { print sum }'
> > PID:16867 mem use(kB):220980
> > [postgres ~]$ p=16867 ; echo -n "PID:$p mem use(kB):" ; \
> > cat /proc/$p/smaps | grep Private | sed -e 's/^.*://' -e 's/kB//' | \
> > awk '{ sum += $1 } ; END { print sum }'
> > PID:16867 mem use(kB):339668
> >
> > （以下結果だけ）
> > PID:16867 mem use(kB):453888
> > PID:16867 mem use(kB):638172
> > PID:16867 mem use(kB):880916
> > PID:16867 mem use(kB):1036772
> > PID:16867 mem use(kB):1289756
> > PID:16867 mem use(kB):1457176
> > PID:16867 mem use(kB):1647164
> > PID:16867 mem use(kB):2012496
> > PID:16867 mem use(kB):2639904
> > PID:16867 mem use(kB):3170596
> > PID:16867 mem use(kB):3504604
> > PID:16867 mem use(kB):3497824
> > PID:16867 mem use(kB):3517192
> > PID:16867 mem use(kB):3491892
> > PID:16867 mem use(kB):3509284
> > PID:16867 mem use(kB):1141636
> > PID:16867 mem use(kB):908084
> > PID:16867 mem use(kB):852668
> > PID:16867 mem use(kB):73376
> > PID:16867 mem use(kB):73372
> > PID:16867 mem use(kB):73376
> > PID:16867 mem use(kB):73372
> > PID:16867 mem use(kB):73372
> >
> >
> > On Wed, 11 Sep 2019 19:10:29 +0900 (JST)
> > "misakana ＠ yahoo.co.jp" <misakana ＠ yahoo.co.jp> wrote:
> >
> > > 初めて投稿いたします。永吉と申します。
> > >
> > > PostgreSQL11でPROCEDUREを使用したPL/pgSQLにてツールを作成しています。
> > > （Ver.11からのトランザクション機能を活用するためPROCEDUREを使用）
> > >
> > > テーブル項目の更新を確認するPROCEDUREを作成し、親となるPROCEDUREから
> > > そのPROCEDUREを繰り返し呼び出す(CALLする)構造にしています。この時、
> > > Windows側で該当するプロセスのメモリ使用量が増加し、総メモリ使用量が
> > > 100%近くなった段階で、PROCEDUREが「ERROR: out of memory」となり停止
> > > してしまいます。
> > >
> > > ＜環境＞
> > > －Windows 7 Professional Service Pack1 64Bit
> > > －実装メモリ ４GB
> > > －PostgreSQL 11.5, compiled by Visual C++ build 1914, 64-bit
> > >
> > > ＜ソース＞ <= 実際は複雑ですが下記だけで再現します。
> > >
> > > CREATE OR REPLACE PROCEDURE pc_dps11e(re_count integer)
> > > LANGUAGE 'plpgsql' AS $BODY$
> > > DECLARE
> > > n integer; -- ループ変数
> > > BEGIN
> > > RAISE NOTICE '## ひたすらプロシジャを呼び出す ##';
> > > RAISE NOTICE 'START : %', TO_CHAR(clock_timestamp(), 'YYYY/MM/DD HH24:MI:SS');
> > >
> > > FOR n IN 1..re_count LOOP
> > > CALL p_dps11z();
> > > END LOOP;
> > > RAISE NOTICE 'END : %', TO_CHAR(clock_timestamp(), 'YYYY/MM/DD HH24:MI:SS');
> > > PERFORM pg_sleep(10.0);
> > > END; $BODY$;
> > >
> > > CREATE OR REPLACE PROCEDURE p_dps11z()
> > > LANGUAGE 'plpgsql' AS $BODY$
> > > BEGIN
> > > -- SELECT * TO REC FROM ...
> > > NULL;
> > > END; $BODY$;
> > >
> > > CALL pc_dps11e(500000);
> > >
> > > PostgreSQL11自体のメモリリークを疑っているのですが、
> > > ご教授いただけたら幸いです。よろしくお願いします。
> > >
> >
> >
> > ______________________________________________________________________
> > 日本PostgreSQLユーザ会 高塚 遥
> > 〒171-0022 東京都豊島区南池袋2-32-8 SRA OSS 日本支社 内 JPUG
> > Mail: harukat ＠ postgresql.jp TEL: 03-5979-2729
>
>
>
> --
> Tatsuhito Kasahara
> kasahara.tatsuhito _at_ gmail.com
pgsql-jp メーリングリストの案内