ここで、PGA Heap Dumpを利用し、メモリリークの原因を追跡する例を見ましょう。
下はFORALLを使用して効率的にデータを生成するProcedureです。
define m_string_length = 20
drop table t1 purge;
create table t1(v1 varchar2( &m_string_length ));
create or replace procedure proc1 (
i_rowcount in number default 1000000,
i_bulk_pause in number default 0,
i_forall_pause in number default 0,
i_free_pause in number default 0
)
as
type w_type is table of varchar2( &m_string_length );
w_list w_type := w_type();
w_free w_type := w_type();
begin
for i in 1..i_rowcount loop
w_list.extend;
w_list(i) := rpad('x', &m_string_length );
end loop;
dbms_lock.sleep(i_bulk_pause);
forall i in 1..w_list.count
insert into t1 values(w_list(i));
dbms_lock.sleep(i_forall_pause);
commit;
w_list := w_free;
dbms_session.free_unused_user_memory;
dbms_lock.sleep(i_free_pause);
end;
/
このProcedureを読み続けながら、メモリ使用率を観察しましょう。
UKJA@ukja102> exec proc1;
PL/SQL procedure successfully completed.
SYS@ukja10> select
2 name, value
3 from
4 v$sesstat ss,
5 v$statname sn
6 where
7 sn.name like '%ga memory%'
8 and ss.statistic# = sn.statistic#
9 and ss.sid = 149
10 ;
NAME VALUE
------------------------------ ----------------
session uga memory 498,942,840
session uga memory max 500,053,908
session pga memory 599,907,924
session pga memory max 675,602,004
UKJA@ukja102> exec proc1;
PL/SQL procedure successfully completed.
NAME VALUE
------------------------------ ----------------
session uga memory 695,429,288
session uga memory max 695,429,288
session pga memory 904,191,572
session pga memory max 904,257,108
UKJA@ukja102> exec proc1;
PL/SQL procedure successfully completed.
NAME VALUE
------------------------------ ----------------
session uga memory 840,565,088
session uga memory max 840,565,088
session pga memory 1,077,861,972
session pga memory max 1,077,861,972
深刻なメモリリークが発生することをわかります。OracleはProcedureの実行済みの後でもメモリを解除していません。
問題はOracleがどのようなObjectについてメモリを非正常的に占有しているのか判別しにくいと言うことです。ここで試せるのがPGA Heap Dumpです。
oradebug setospid 6760
oradebug dump heapdump 1
Heap Dump File自体は読みやすいですが、長さがとても長い場合が多くあります。それで、heap_analyze.sqlを利用してサマリ結果を見ましょう。
UKJA@ukja102> @heap_analyze heap_dump_1.trc
UKJA@ukja102> set echo off
ATYPE CSIZE TOTAL_HEAP_SIZE RATIO
------------------------ ---------- --------------- -------
free 99660580 598579832 16.650
freeable 498650144 598579832 83.306
perm 181928 598579832 .030
recreate 87180 598579832 .015
Elapsed: 00:00:01.03
CTYPE CSIZE TOTAL_HEAP_SIZE RATIO
------------------------------ ---------- --------------- -------
Alloc environm 4144 598579832 .001
Fixed Uga 20572 598579832 .003
KFIO PGA struct 72 598579832 .000
KFK PGA 260 598579832 .000
KJZT context 60 598579832 .000
KSFQ heap 3928 598579832 .001
KSFQ heap descr 92 598579832 .000
PLS cca hp desc 212 598579832 .000
PLS non-lib hp 18560 598579832 .003
callheap 2144 598579832 .000
external name 24 598579832 .000
joxp heap 2000 598579832 .000
kews sqlstat st 1292 598579832 .000
kgh stack 17012 598579832 .003
kjztprq struct 2068 598579832 .000
koh-kghu call h 1328 598579832 .000
kopolal dvoid 2524 598579832 .000
kpuinit env han 1584 598579832 .000
kzsna:login nam 24 598579832 .000
ldm context 12712 598579832 .002
perm 181928 598579832 .030
qmtmInit 13980 598579832 .002
session heap 498632732 598579832 83.303
99660580 598579832 16.650
24 rows selected.
Elapsed: 00:00:01.12
DS CSIZE TOTAL_SUBHEAP_SIZE RATIO
-------------------- ---------- ------------------ -------
083BD9CC 10320 498590012 .002
08563470 12436 498590012 .002
085A7600 498567256 498590012 99.995
Elapsed: 00:00:00.76
Subheap(08563470)が全体のメモリの80%以上を占めるのが見えます。次の作業はSubheap Dumpを実行することです。
oradebug dump heapdump_addr 1 0xa067600
UKJA@ukja102> @heap_analyze heap_subdump_1.trc
UKJA@ukja102> set echo off
ATYPE CSIZE TOTAL_HEAP_SIZE RATIO
------------------------ ---------- --------------- -------
free 9701516 498589224 1.946
freeable 488817960 498589224 98.040
perm 54896 498589224 .011
recreate 14852 498589224 .003
Elapsed: 00:00:00.70
CTYPE CSIZE TOTAL_HEAP_SIZE RATIO
------------------------------ ---------- --------------- -------
PLS cca hp desc 400 498589224 .000
PLS non-lib hp 488740608 498589224 98.025
Session NCHAR l 552 498589224 .000
kgict 40 498589224 .000
kgicttab 44 498589224 .000
kgicu 92 498589224 .000
kgiob 1928 498589224 .000
kgiobdtb 192 498589224 .000
kgsc ht segs 5720 498589224 .001
koddcal dvoid 24 498589224 .000
kodmcon kodmc 64 498589224 .000
kodpai image 1036 498589224 .000
koh-kghu sessi 15888 498589224 .003
koh-kghu sessio 14252 498589224 .003
kokahin kgglk 140 498589224 .000
kokl lob id has 1036 498589224 .000
kokl transactio 268 498589224 .000
koklug hlctx in 24 498589224 .000
koklug hxctx in 24 498589224 .000
kpuinit env han 1584 498589224 .000
kqlpWrntoStr:st 112 498589224 .000
ksulu : ksulueo 40 498589224 .000
kwqaalag 92 498589224 .000
kwqb context me 92 498589224 .000
kwqica hash tab 92 498589224 .000
kwqidwh memory 92 498589224 .000
kwqmahal 92 498589224 .000
kxs-heap-d 1036 498589224 .000
kxs-heap-p 4148 498589224 .001
kxs-krole 780 498589224 .000
kxsFrame4kPage 28840 498589224 .006
kxsc: kkspbd0 968 498589224 .000
kxsc: kkspsc0 7756 498589224 .002
kzctxhugi1 4108 498589224 .001
kzsrcrdi 60 498589224 .000
perm 54896 498589224 .011
session languag 552 498589224 .000
system trigger 36 498589224 .000
9701516 498589224 1.946
39 rows selected.
Elapsed: 00:00:00.81
DS CSIZE TOTAL_SUBHEAP_SIZE RATIO
-------------------- ---------- ------------------ -------
08B3608C 2076 488746828 .000
08B3EAAC 488738512 488746828 99.998
08B578F4 2080 488746828 .000
08B5A114 2080 488746828 .000
0FD400B0 2080 488746828 .000
Elapsed: 00:00:00.89
同じPatternで、Subheap(08B3EAAC)が大部分のメモリを占めるものが分かります。
oradebug dump heapdump_addr 1 0x0A08EAAC
UKJA@ukja102> @heap_analyze heap_subdump_2.trc
UKJA@ukja102> set echo off
ATYPE CSIZE TOTAL_HEAP_SIZE RATIO
------------------------ ---------- --------------- -------
free 483911940 488662624 99.028
freeable 4750540 488662624 .972
perm 144 488662624 .000
Elapsed: 00:00:05.03
CTYPE CSIZE TOTAL_HEAP_SIZE RATIO
------------------------------ ---------- --------------- -------
DPAGE 4750096 488662624 .972
peihstdep 260 488662624 .000
perm 144 488662624 .000
pl_iot_alloc 92 488662624 .000
pl_lut_alloc 92 488662624 .000
483911940 488662624 99.028
6 rows selected.
Elapsed: 00:00:05.40
no rows selected
Elapsed: 00:00:03.21
今、問題の原因が見えます。OracleはFORALLで使用されたメモリをfree状態に変えたにもかかわらず、そのメモリを完全に解除していないと言えます。これは間違いなくBugだと考えられます。
次のようにMetalinkで検索してみます。
検索の結果(Bug# 5866410)が上で見た現状と完璧に一致しています。
Bulk insert in PLSQL can consume a large amount of PGA memory which can lead to ORA-4030 errors.
A heapdump will show lot of free memory in the free lists which is not used but instead fresh allocations are made.
PGA Heap Dump分析がいくら有用か分かる良い例です。でも、実際には分析は見えるものより難しい場合が多くあります。理由は
- Heap Dump Fileは長すぎる場合が多いです。適切なツールがなければ、分析はほとんど不可能です。上で紹介したheap_analyze.sqlがいい例です。
- Heapは階層的な構造を持っているため、分析時に注意が必要です。
- Object名を理解しにくい場合も多くあります。
このような限界にもかかわらず、特定状況ではPGA Heap Dump分析は大きい力を発揮します。そのメリトとデメリトを良く理解した後使用すれば立派な分析ツールとなるでしょう。
Posts
No comments:
Post a Comment