Oracle Database - Multi Row INSERT、バインド変数を使うとリテラル値を使う場合では見える景色が変わるんだよね #4 - The SQL was transformed!
Previously on Mac De Oracle
前回は、Oracle Database - Multi Row INSERT、バインド変数を使うとリテラル値を使う場合では見える景色が変わるんだよね #3 - ローカル表とリモート表での挙動の差異?! でした。
復習を兼ねて、前回の表(再掲)をみつつ。23aiでサポートされたMulti row Insert文をローカル表とリモート表(via DB Link)へ実行してみると。。なんと。想定外の結果に。。。
v$mystatから得られた統計値をみると、execution countやparse count (total) - parse count (hard) それに伴うパースタイムなどなど、一体何が起きてるの。。。。。(ニヤニヤ
という感じでした。
さらに、リモート表に対して、1,000 rows / INSERT で Multi row Insert すると、OPEN_CURSORS = 300(default)では足らず、 1,300まで増やすと不足しないという、状況。
なにか引っかかりますよね。単純にSQLをまるっとリモートDB (インスタンスは同じだけど、DB Linkでパススルーして投げているだけでは??。。。と思っていたが) へ投げているだけではなさそうな様子。
ということで、その謎を追い Oracle Database の奥へ進んでいきましょう ;)
まずは、10046トレースでローカル表とリモート表への実行でどういう差があるのかを見ておく。
バインド変数を利用し、1000 rows / INSERTをローカル表へ実行した場合の10046トレース
Oracle Database 23ai Free Release 23.0.0.0.0 - Develop, Learn, and Run for Free
Version 23.8.0.25.04
に接続されました。
SCOTT@localhost:1521/freepdb1> alter session set tracefile_identifier='10046_mrows_local';
セッションが変更されました。
SCOTT@localhost:1521/freepdb1> alter session set statistics_level=all;
セッションが変更されました。
SCOTT@localhost:1521/freepdb1> alter session set max_dump_file_size = unlimited;
セッションが変更されました。
SCOTT@localhost:1521/freepdb1> alter system flush shared_pool;
システムが変更されました。
SCOTT@localhost:1521/freepdb1> alter session set events '10046 trace name context forever,level 12';
セッションが変更されました。
SCOTT@localhost:1521/freepdb1> @multi_row_insert_bind_1000 100000 1000
SID NAME VALUE
---------- ---------------------------------------------------------------- ----------
201 CPU used by this session 38
201 CPU used when call started 36
201 SQL*Net roundtrips to/from client 11
...略...
201 execute count 2329
...略...
201 session pga memory 6696608
201 session pga memory max 9055904
201 session uga memory 3178192
201 session uga memory max 4776536
...略...
PL/SQLプロシージャが正常に完了しました。
経過: 00:00:02.79
SID NAME VALUE
---------- ---------------------------------------------------------------- ----------
201 CPU used by this session 313
201 CPU used when call started 313
201 SQL*Net roundtrips to/from client 16
...略...
201 execute count 2724
...略...
201 session pga memory 8055800
201 session pga memory max 52702880
201 session uga memory 4658456
201 session uga memory max 4776536
...略...
201 user commits 100
...略...
COUNT(1)
----------
100000
...略...
SCOTT@localhost:1521/freepdb1> alter session set events '10046 trace name context off';
...略...
バインド変数を利用し、1000 rows / INSERTをリモート表(via DB Link)へ実行した場合の10046トレース
Oracle Database 23ai Free Release 23.0.0.0.0 - Develop, Learn, and Run for Free
Version 23.8.0.25.04
に接続されました。
SCOTT2@localhost:1521/freepdb1> alter session set tracefile_identifier='10046_mrows_remote';
セッションが変更されました。
SCOTT2@localhost:1521/freepdb1> alter session set statistics_level=all;
セッションが変更されました。
SCOTT2@localhost:1521/freepdb1> alter session set max_dump_file_size = unlimited;
セッションが変更されました。
SCOTT2@localhost:1521/freepdb1> alter system flush shared_pool;
システムが変更されました。
SCOTT2@localhost:1521/freepdb1> alter session set events '10046 trace name context forever,level 12';
セッションが変更されました。
SCOTT2@localhost:1521/freepdb1> @multi_row_insert_bind_1000 100000 1000
SID NAME VALUE
---------- ---------------------------------------------------------------- ----------
201 CPU used by this session 20
201 CPU used when call started 18
201 SQL*Net roundtrips to/from client 11
...略...
201 execute count 2661
...略...
201 session pga memory 7024288
201 session pga memory max 9121440
201 session uga memory 3769944
201 session uga memory max 5045168
...略...
PL/SQLプロシージャが正常に完了しました。
経過: 00:00:28.67
SID NAME VALUE
---------- ---------------------------------------------------------------- ----------
201 CPU used by this session 1653
201 CPU used when call started 1653
201 SQL*Net roundtrips to/from client 16
201 SQL*Net roundtrips to/from dblink 202411
...略...
201 execute count 103112
...略...
201 session pga memory 14167712
201 session pga memory max 27799200
201 session uga memory 11361872
201 session uga memory max 12865392
...略...
201 user commits 100
...略...
COUNT(1)
----------
100000
...略...
SCOTT2@localhost:1521/freepdb1> alter session set events '10046 trace name context off';
...略...
出力された10046トレースファイルのサイズ。リモートのほうが圧倒的に大きいですね。
[oracle@arm64-oraclelinux8u10 trace]$ ll FREE_ora_*_10046_mrows_*.trc
-rw-r-----. 1 oracle oinstall 62680689 Feb 3 22:16 FREE_ora_4704_10046_mrows_local.trc
-rw-r-----. 1 oracle oinstall 136508011 Feb 3 22:19 FREE_ora_4724_10046_mrows_remote.trc
比較しつつ覗いてみると。
ローカル表への Multi Row Insert では、投げたままのSQL文がみつかります。これは想定通りですよね。
...略...
SQL ID: 7vkx7q1gbfwr3 Plan Hash: 1
INSERT INTO mrows_ins_tab
VALUES
(:c11, null, null, null, null, null, null, null, :c81), (:c12, null, null,
null, null, null, null, null, :c82), (:c13, null, null, null, null, null,
null, null, :c83), (:c14, null, null, null, null, null, null, null, :c84),
(:c15, null, null, null, null, null, null, null, :c85), (:c16, null, null,
null, null, null, null, null, :c86), (:c17, null, null, null, null, null,
null, null, :c87), (:c18, null, null, null, null, null, null, null, :c88),
(:c19, null, null, null, null, null, null, null, :c89), (:c110, null, null,
null, null, null, null, null, :c810), (:c111, null, null, null, null, null,
...略...
null, null, null, null, :c8994), (:c1995, null, null, null, null, null,
null, null, :c8995), (:c1996, null, null, null, null, null, null, null,
:c8996), (:c1997, null, null, null, null, null, null, null, :c8997),
(:c1998, null, null, null, null, null, null, null, :c8998), (:c1999, null,
null, null, null, null, null, null, :c8999), (:c11000, null, null, null,
null, null, null, null, :c81000);
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.13 0.13 0 0 0 0
Execute 100 1.81 1.84 7 7031 61178 100000
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 101 1.95 1.98 7 7031 61178 100000
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 134 (recursive depth: 1)
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
0 0 0 LOAD TABLE CONVENTIONAL MROWS_INS_TAB (cr=519 pr=8 pw=0 time=7342 us starts=1 direct read=0 direct write=0)
1000 1000 1000 VALUES SCAN (cr=0 pr=0 pw=0 time=633 us starts=1 direct read=0 direct write=0 cost=2000 size=0 card=1000)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
Allocate PGA memory from OS 2 0.00 0.00
Allocate CGA memory from OS 62 0.00 0.00
Disk file operations I/O 2 0.00 0.00
db file sequential read 7 0.00 0.00
log file switch (private strand flush incomplete)
2 0.00 0.01
一方、リモート表に対して同一Multi Row Insert文を実行した場合の10046トレースでは。。。
やたらと、SYS.DUALへのSELECT文が出現しており、それにより10046トレースファイルサイズが大きくなっていました。
見えて来ましたよね。なんとなく。。。。
SQL ID: 7vkx7q1gbfwr3 Plan Hash: 0
INSERT INTO mrows_ins_tab
VALUES
(:c11, null, null, null, null, null, null, null, :c81), (:c12, null, null,
null, null, null, null, null, :c82), (:c13, null, null, null, null, null,
null, null, :c83), (:c14, null, null, null, null, null, null, null, :c84),
(:c15, null, null, null, null, null, null, null, :c85), (:c16, null, null,
null, null, null, null, null, :c86), (:c17, null, null, null, null, null,
null, null, :c87), (:c18, null, null, null, null, null, null, null, :c88),
(:c19, null, null, null, null, null, null, null, :c89), (:c110, null, null,
...略...
null, null, null, null, :c8994), (:c1995, null, null, null, null, null,
null, null, :c8995), (:c1996, null, null, null, null, null, null, null,
:c8996), (:c1997, null, null, null, null, null, null, null, :c8997),
(:c1998, null, null, null, null, null, null, null, :c8998), (:c1999, null,
null, null, null, null, null, null, :c8999), (:c11000, null, null, null,
null, null, null, null, :c81000);
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.13 0.14 0 0 0 0
Execute 100 14.90 26.22 0 18 100 100000
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 101 15.04 26.36 0 18 100 100000
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 136 (recursive depth: 1)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
Allocate PGA memory from OS 2 0.00 0.00
single-task message 1 0.36 0.36
SQL*Net message from dblink 202312 0.17 18.65
SQL*Net message to dblink 202311 0.00 0.12
SQL*Net more data to dblink 5800 0.00 0.02
********************************************************************************
...略...
SELECT /*+ FULL(P) +*/ *
FROM
"SYS"."DUAL" P
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1002 0.00 0.00 0 0 0 0
Execute 0 0.00 0.00 0 0 0 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 1002 0.00 0.00 0 0 0 0
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 136 (recursive depth: 2)
********************************************************************************
...略...
SQL ID: 40x1xzzgzd101 Plan Hash: 1388734953
SELECT 0
FROM
"SYS"."DUAL" "A1002"
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 100 0.00 0.00 0 0 0 0
Execute 100 0.00 0.00 0 0 0 0
Fetch 200 0.00 0.00 0 0 0 100
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 400 0.00 0.00 0 0 0 100
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 136 (recursive depth: 2)
Number of plan statistics captured: 100
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
1 1 1 FAST DUAL (cr=0 pr=0 pw=0 time=0 us starts=1 direct read=0 direct write=0 cost=2 size=0 card=1)
...略...
SYS.DUALへのアクセスが目立つ、かつ、SYS.DUALへの表エイリアスが皆異なるようなので、SYS.DUALだけで何行あるかカウントしてみました。
おおおおおおおおおおーーーー!!!!!! これって!!
リモート表へMulti Row Insertを実行した場合のSYS.DUALへのアクセスを含む単純なSELECT文の数!! は、 1,002件!!!!
[oracle@arm64-oraclelinux8u10 trace]$ cat FREE_ora_4724_10046_mrows_remote_aggregate.txt | grep "SELECT 0" | wc -l
1002
[oracle@arm64-oraclelinux8u10 trace]$ cat FREE_ora_4704_10046_mrows_local_aggregate.txt | grep "SELECT 0" | wc -l
0
23aiからサポートされた、Multi Row Insert 構文って、内部で TRANSFORM されちゃってないですかね???
10053トレースを取得すれば確実に見えるはず。。。。。。
10046トレースと同様の方法で。。
ローカル表で。
SCOTT2@localhost:1521/freepdb1> alter session set tracefile_identifier='10053_mrows_local';
セッションが変更されました。
...略...
SCOTT@localhost:1521/freepdb1> alter session set events '10053 trace name context forever, level 1';
セッションが変更されました。
SCOTT@localhost:1521/freepdb1> @multi_row_insert_bind_1000 100000 1000
...略...
リモート表で。
SCOTT2@localhost:1521/freepdb1> alter session set tracefile_identifier='10053_mrows_remote';
セッションが変更されました。
...略...
SCOTT2@localhost:1521/freepdb1> alter session set events '10053 trace name context forever, level 1';
セッションが変更されました。
SCOTT2@localhost:1521/freepdb1> @multi_row_insert_bind_1000 100000 1000
...略...
10053トレースログを見てみると。。。
はっけーーーーーーーーーーーーーーーーーん!!
23ai以降でサポートされたMulti Row Insert文は、ローカル表でもリモート表でも同様にTRANSFORMされていました!!!!!
INSERT INTO 表[(列...)] VALUES
(列...)
, (列...)
, ....;
は、内部的に以下のように、行毎に SYS.DUALをアクセスするSELECT文に分解された後、UNION ALL で縦方向に結合されたインラインビューに!!
INSERT INTO 表[(列...)]
SELECT 列... FROM
(
SELECT 列... FROM SYS.DUAL
UNION ALL
SELECT 列... FROM SYS.DUAL
UNION ALL
....
)
のように書き換えられて実行される。
これはリモート表でもローカル表でも書き換えられています。
では、なにが大きな負荷なっているのか。。
それは、23ai以降、記述が必須ではなくなった、そう、DUAL 表!!!!!
以下のように書き換えられた、Multi row insert 文において、mrows_ins_tab がローカル表である場合は、同一インスタンスのオブジェクトだけを参照するので問題はありません。
高速です!(この形に書き換えられてたのは今知ったのですがw)
INSERT INTO mrows_ins_tab
SELECT 列... FROM
(
SELECT 列... FROM SYS.DUAL
UNION ALL
SELECT 列... FROM SYS.DUAL
UNION ALL
....
)
ところが、mrows_ins_tab が DB Link 経由のリモート表である場合、ローカル表扱いの SYS.DUAL が重荷になってきます!!!!
俺書いてないけど! DUAL。
想定では、execution countは、Multi Row Insert文が実行された回数を想定していましたが、Insert対象の表がリモート表である場合は、SYS.DUALはローカル扱いのままなので、
リモートDML(すべてのオブジェクトがDBリンクの先のDBとして扱われる)ではなく、分散DMLとなり、ローカルのSYS.DUALが、合計で 100,000回アクセスされ、それに加えて、リモート表へのINSERT文が、Multi Row Insert文の実行回数分加わる!!
今一度、冒頭の表(前回のエントリの表再掲)を見つつ確認してみましょう!!!
リモート表へのexecute count謎の増加理由
1)10 rows / INSERT 10 rows / INSERT毎に10,000回実行して 100,000行インサートする場合、リモート表だと、
10 rows * 10,000回 + 10,000回 = 110,000回 + recursive call分なのどオーバーヘッド
(想定していた、execute countは、 10,000 + recursive call overhead程度)
2) 100 rows / INSERT 100 rows / INSERT毎に1,000回実行して 100,000行インサートする場合、リモート表だと、
100 rows * 1,000回 + 1,000回 = 101,000回 + recursive call分なのどオーバーヘッド
(想定していた、execute countは、 1,000 + recursive call overhead程度)
3) 1,000 rows / INSERT 1,000 rows / INSERT毎に100回実行して 100,000行インサートする場合、リモート表だと、
1,000 rows * 100回 + 100回 = 100,100回 + recursive call分なのどオーバーヘッド
(想定していた、execute countは、 100 + recursive call overhead程度)
リモート表へのMulti Row Insertのexecute countの実測値と合っていますよね!! その結果、ソフトパースも同様に上昇、パース時間も増加、おそらく、SQL*Net roundtrips to/from dblinkもその影響で増加しているはずです。
やっと、謎が解けた。。。。。
ということで、PL/SQLで、Bulk Loadするなら、FORALL構文なのですが、FORALL構文はそもそもリモート表には行えません!
Multi Row Insert が使えるかなーと思いましたが、PL/SQLではローカル表としてアクセスする場合以外は、避けた方がよいですね。いまのところ。
どうしてもPL/SQLでリモート表へバルクロードしなければいけないという辛い状況では、ぐるぐる系でSingle Row Insertしつつ、Commitの間隔を100, 1000などのように調整する泥臭い方式しかないのではないでしょうか。。
なお、リモートへパススルーできないかなーと、ヒントを試しましたが効果はありませんでした。残念
ということで、PL/SQLで無理やり、ネットワークラウンドトリップの影響を含めてみるのは諦めましたw
より一般的に、APサーバーとDBサーバー間のネットワークラウンドドリップの影響も含むMulti row Insert vs Single row insert + commit interval方式で、
ぐーるぐーる vs ぐるぐる で比較しつつ、このシリーズをまとめることにしましょう!
なお、Javaのコード書くのめんどくさくなったので、Geminiくんに書いてもらって多少追加して。。。本題へ戻る。。。
To be Continued....
おまけの10053トレース抜粋 ローカル表でもリモート表でも以下のようにトランスフォームされる。1,000 rows / INSERTの場合。
[oracle@arm64-oraclelinux8u10 trace]$ view FREE_ora_5503_10053_mrows_remote.txt
Query after VW_MRG2:
qb SEL$1 (#0):******* UNPARSED QUERY IS *******
SELECT :B1,NULL,NULL,NULL,NULL,NULL,NULL,NULL,:B2 FROM "SYS"."DUAL" "DUAL"
...略...
Query after VW_MRG2:
qb SEL$1000 (#0):******* UNPARSED QUERY IS *******
SELECT :B1,NULL,NULL,NULL,NULL,NULL,NULL,NULL,:B2 FROM "SYS"."DUAL" "DUAL"
Query after VW_MRG2:
qb SET$1 (#0):******* UNPARSED QUERY IS *******
(SELECT :B1 ":1",NULL "NULL",NULL "NULL",NULL "NULL",NULL "NULL",NULL "NULL",NULL "NULL",NULL "NULL",:B2 ":1" FROM "SYS"."DUAL" "DUAL") UNION ALL
(SELECT :B3,NULL,NULL,NULL,NULL,NULL,NULL,NULL,:B4 FROM "SYS"."DUAL" "DUAL") UNION ALL (SELECT :B5,NULL,NULL,NULL,NULL,NULL,NULL,NULL,:B6 FROM "SYS"."DUAL" "DUAL") UNION ALL
(SELECT :B7,NULL,NULL,NULL,NULL,NULL,NULL,NULL,:B8 FROM "SYS"."DUAL" "DUAL") UNION ALL (SELECT :B9,NULL,NULL,NULL,NULL,NULL,NULL,NULL,:B10 FROM "SYS"."DUAL" "DUAL") UNION ALL
(SELECT :B11,NULL,NULL,NULL,NULL,NULL,NULL,NULL,:B12 FROM "SYS"."DUAL" "DUAL") UNION ALL (SELECT :B13,NULL,NULL,NULL,NULL,NULL,NULL,NULL,:B14 FROM "SYS"."DUAL" "DUAL") UNION ALL
(SELECT :B15,NULL,NULL,NULL,NULL,NULL,NULL,NULL,:B16 FROM "SYS"."DUAL" "DUAL") UNION ALL (SELECT :B17,NULL,NULL,NULL,NULL,NULL,NULL,NULL,:B18 FROM "SYS"."DUAL" "DUAL") UNION ALL
(SELECT :B19,NULL,NULL,NULL,NULL,NULL,NULL,NULL,:B20 FROM "SYS"."DUAL" "DUAL") UNION ALL (SELECT :B21,NULL,NULL,NULL,NULL,NULL,NULL,NULL,:B22 FROM "SYS"."DUAL" "DUAL") UNION ALL
(SELECT :B23,NULL,NULL,NULL,NULL,NULL,NULL,NULL,:B24 FROM "SYS"."DUAL" "DUAL") UNION ALL (SELECT :B25,NULL,NULL,NULL,NULL,NULL,NULL,NULL,:B26 FROM "SYS"."DUAL" "DUAL") UNION ALL
(SELECT :B27,NULL,NULL,NULL,NULL,NULL,NULL,NULL,:B28 FROM "SYS"."DUAL" "DUAL") UNION ALL (SELECT :B29,NULL,NULL,NULL,NULL,NULL,NULL,NULL,:B30 FROM "SYS"."DUAL" "DUAL") UNION ALL
(SELECT :B31,NULL,NULL,NULL,NULL,NULL,NULL,NULL,:B32 FROM "SYS"."DUAL" "DUAL") UNION ALL (SELECT :B33,NULL,NULL,NULL,NULL,NULL,NULL,NULL,:B34 FROM "SYS"."DUAL" "DUAL") UNION ALL
(SELECT :B35,NULL,NULL,NULL,NULL,NULL,NULL,NULL,:B36 FROM "SYS"."DUAL" "DUAL") UNION ALL (SELECT :B37,NULL,NULL,NULL,NULL,NULL,NULL,NULL,:B38 FROM "SYS"."DUAL" "DUAL") UNION ALL
(SELECT :B39,NULL,NULL,NULL,NULL,NULL,NULL,NULL,:B40 FROM "SYS"."DUAL" "DUAL") UNION ALL (SELECT :B41,NULL,NULL,NULL,NULL,NULL,NULL,NULL,:B42 FROM "SYS"."DUAL" "DUAL") UNION ALL
...略...
(SELECT :B1991,NULL,NULL,NULL,NULL,NULL,NULL,NULL,:B1992 FROM "SYS"."DUAL" "DUAL") UNION ALL (SELECT :B1993,NULL,NULL,NULL,NULL,NULL,NULL,NULL,:B1994 FROM "SYS"."DUAL" "DUAL") UNION ALL
(SELECT :B1995,NULL,NULL,NULL,NULL,NULL,NULL,NULL,:B1996 FROM "SYS"."DUAL" "DUAL") UNION ALL (SELECT :B1997,NULL,NULL,NULL,NULL,NULL,NULL,NULL,:B1998 FROM "SYS"."DUAL" "DUAL") UNION ALL
(SELECT :B1999,NULL,NULL,NULL,NULL,NULL,NULL,NULL,:B2000 FROM "SYS"."DUAL" "DUAL")
関連エントリ
・帰ってきた! 標準はあるにはあるが癖の多いSQL #20 - Table Value Constructer (TVC)
・帰ってきた! 標準はあるにはあるが癖の多いSQL #21 - Table Value Constructer(TVC)- ハードパース時間とメモリ消費量 / BONUS TRACK
・帰ってきた! 標準はあるにはあるが癖の多いSQL #22 - Multi Row INSERT
・Oracle Database - Multi Row INSERT、バインド変数を使うと、リテラル値を使う場合では見える景色が変わるんだよね #1 - バグなのか現時点の仕様なのか?
・Oracle Database - Multi Row INSERT、バインド変数を使うとリテラル値を使う場合では見える景色が変わるんだよね #2
・Oracle Database - Multi Row INSERT、バインド変数を使うとリテラル値を使う場合では見える景色が変わるんだよね #3 - ローカル表とリモート表での挙動の差異?!






























































最近のコメント