Online Statistics Gathering for Bulk Loads Online Statistics GatheringThis Blog will discuss its side effects in 3 aspects:
Read Committed (default transaction isolation level) Global Temporary Table (GTT) Deadlock with MMON Slave Process (Mnnn)Note: All tests are done in Oracle 12.1.0.2.0 and 12.2.0.1.0
1. Online Statistics Gathering
xplan is adjusted with one additional Row Source line marked as "OPTIMIZER STATISTICS GATHERING". And it is exposed in DBA_TAB_COL_STATISTICS.NOTES column as "STATS_ON_LOAD ".
SQL(100) > drop table test_tab;
SQL(100) > create table test_tab(x number, y number);
SQL(100) > explain plan for insert /*+ append */ into test_tab select level x, mod(level, 4) y from dual connect by level <= 4321;
SQL(100) > select * from table(dbms_xplan.display);
---------------------------------------------------------------------------------------
Plan hash value: 1541388231
-------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Cost (%CPU)| Time |
-------------------------------------------------------------------------------------
| 0 | INSERT STATEMENT | | 1 | 2 (0)| 00:00:01 |
| 1 | LOAD AS SELECT | TEST_TAB | | | |
| 2 | OPTIMIZER STATISTICS GATHERING | | 1 | 2 (0)| 00:00:01 |
|* 3 | CONNECT BY WITHOUT FILTERING | | | | |
| 4 | FAST DUAL | | 1 | 2 (0)| 00:00:01 |
-------------------------------------------------------------------------------------
SQL(100) > insert /*+ append */ into test_tab select level x, mod(level, 4) y from dual connect by level <= 4321;
SQL(100) > select owner, table_name, column_name, num_distinct, last_analyzed, '"'||notes||'"'
from dba_tab_col_statistics
where table_name in ('TEST_TAB') and notes like '%STATS_ON_LOAD%';
OWNER TABLE_NAME COLUMN_NAME NUM_DISTINCT LAST_ANALYZED NOTES
------ ----------- ------------ ------------- --------------------- ----------------
K TEST_TAB X 4321 2018-JUL-03 08:08:09 "STATS_ON_LOAD "
K TEST_TAB Y 4 2018-JUL-03 08:08:09 "STATS_ON_LOAD "
SQL(100) > commit;
Statement level hints:
no_gather_optimizer_statistics
or
OPT_PARAM('_optimizer_gather_stats_on_load' 'false')
Session level:
alter session set "_optimizer_gather_stats_on_load"=false;
System level:
alter system set "_optimizer_gather_stats_on_load"=false;
2. Read Committed Violation
At first, look the new behaviour of Read Committed as Oracle default transaction isolation level:
---========= (1-1): Session_1@T1 =========---
SQL(100) > drop table test_tab;
SQL(100) > create table test_tab(x number, y number);
SQL(100) > insert /*+ append */ into test_tab select level x, mod(level, 4) y from dual connect by level <= 4321;
4321 rows created.
---========= (1-2): Session_2@T2 =========---
SQL(200) > select table_name, num_rows, last_analyzed from dba_tables where table_name in ('TEST_TAB');
TABLE_NAME NUM_ROWS LAST_ANALYZED
------------ ---------- --------------------
TEST_TAB 4321 2018*JUN*29 10:52:41
SQL(200) > explain plan for select * from test_tab;
SQL(200) > select * from table(dbms_xplan.display);
------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 4321 | 30247 | 30 (0)| 00:00:01 |
| 1 | TABLE ACCESS FULL| TEST_TAB | 4321 | 30247 | 30 (0)| 00:00:01 |
------------------------------------------------------------------------------
---========= (1-3): Session_1@T3 =========---
SQL(100) > rollback;
SQL(100) > insert /*+ append */ into test_tab select level x, mod(level, 4) y from dual connect by level <= 1234;
1234 rows created.
---========= (1-4): Session_2@T4 =========---
SQL(200) > select table_name, num_rows, last_analyzed from dba_tables where table_name in ('TEST_TAB');
TABLE_NAME NUM_ROWS LAST_ANALYZED
------------ ---------- -------------
TEST_TAB
SQL(200) > explain plan for select * from test_tab;
SQL(200) > select * from table(dbms_xplan.display);
------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 82 | 574 | 2 (0)| 00:00:01 |
| 1 | TABLE ACCESS FULL| TEST_TAB | 82 | 574 | 2 (0)| 00:00:01 |
------------------------------------------------------------------------------
If rollback IAS and insert again, there is no more Online Statistics Gathering. So this feature is only waked up on the first IAS.
As a consequence, Xplan is created based on un-committed data, potentially volatile xplan and unstable performance.
Continue our test, if we truncate the table and insert again (also without commit), Online Statistics Gathering recurs again as demonstrated below:
---========= (1-5): Session_1@T5 =========---
SQL(100) > truncate table test_tab;
SQL(100) > insert /*+ append */ into test_tab select level x, mod(level, 4) y from dual connect by level <= 9876;
---========= (1-6): Session_2@T6 =========---
SQL(200) > select table_name, num_rows, last_analyzed from dba_tables where table_name in ('TEST_TAB');
TABLE_NAME NUM_ROWS LAST_ANALYZED
------------ ---------- --------------------
TEST_TAB 9876 2018*JUN*29 10:58:41
SQL(200) > explain plan for select * from test_tab;
SQL(200) > select * from table(dbms_xplan.display);
------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 9876 | 69132 | 4 (0)| 00:00:01 |
| 1 | TABLE ACCESS FULL| TEST_TAB | 9876 | 69132 | 4 (0)| 00:00:01 |
------------------------------------------------------------------------------
3. Global Temporary Table
Repeat the same test for GTT with commit delete rows.
---========= (2-1): Session_1@T7 =========---
SQL(100) > rollback;
SQL(100) > drop table test_tab;
SQL(100) > create global temporary table test_tab(x number, y number) on commit delete rows;
SQL(100) > insert /*+ append */ into test_tab select level x, mod(level, 4) y from dual connect by level <= 4321;
4321 rows created.
---========= (2-2): Session_2@T8 =========---
SQL(200) > select table_name, num_rows, last_analyzed from dba_tables where table_name in ('TEST_TAB');
TABLE_NAME NUM_ROWS LAST_ANALYZED
------------ ---------- --------------------
TEST_TAB 4321 2018*JUN*29 11:19:36
SQL(200) > explain plan for select * from test_tab;
SQL(200) > select * from table(dbms_xplan.display);
------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 4321 | 30247 | 30 (0)| 00:00:01 |
| 1 | TABLE ACCESS FULL| TEST_TAB | 4321 | 30247 | 30 (0)| 00:00:01 |
------------------------------------------------------------------------------
---========= (2-3): Session_1@T9 =========---
SQL(100) > rollback;
SQL(100) > insert /*+ append */ into test_tab select level x, mod(level, 4) y from dual connect by level <= 1234;
1234 rows created.
---========= (2-4): Session_2@T10 =========---
SQL(200) > select table_name, num_rows, last_analyzed from dba_tables where table_name in ('TEST_TAB');
TABLE_NAME NUM_ROWS LAST_ANALYZED
------------ ---------- --------------------
TEST_TAB 1234 2018*JUN*29 11:21:16
SQL(200) > explain plan for select * from test_tab;
SQL(200) > select * from table(dbms_xplan.display);
------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1234 | 8638 | 30 (0)| 00:00:01 |
| 1 | TABLE ACCESS FULL| TEST_TAB | 1234 | 8638 | 30 (0)| 00:00:01 |
------------------------------------------------------------------------------
In contrary to normal table, if rollback IAS and insert again, Online Statistics is re-gathered.
If GTT is created with commit preserve rows, the behavior is similar to normal table.
However Oracle 12c Documentation said that bulk loads do not gather statistics automatically when target table is global temporary table defined as ON COMMIT DELETE ROWS (see Online Statistics Gathering for Bulk Loads ).
The default GTT behaviour ('SHARED') can be turned off by global or table prefs:
exec dbms_stats.set_global_prefs ('GLOBAL_TEMP_TABLE_STATS','SESSION');
exec dbms_stats.set_table_prefs(null, 'TEST_TAB', 'GLOBAL_TEMP_TABLE_STATS', 'SESSION');
select dbms_stats.get_prefs('GLOBAL_TEMP_TABLE_STATS') from dual;
4. Internals
Turn on SQL Trace (10046), perform 3 IAS operations and one CTAS, trace files show the call of dbms_stats.postprocess_stats, which is probably gathering Online Statistics.
IAS - insert
BEGIN dbms_stats.postprocess_stats(:owner, :tabname, :partname, :subpartname, 2, :rawstats, :selmap, :clist); END;
IAS - commit
BEGIN dbms_stats.postprocess_stats(:owner, :tabname, :partname, :subpartname, 1, null, null, null); END;
IAS - rollback
BEGIN dbms_stats.postprocess_stats(:owner, :tabname, :partname, :subpartname, 8, null, null, null); END;
CTAS
create table test_tab as select level x, mod(level, 4) y from dual connect by level <= 4321;
BEGIN dbms_stats.postprocess_stats(:owner, :tabname, :partname, :subpartname, 6, :rawstats, :selmap, :clist); END;
With dbms_stats Tracing, we can also observe this call:
SQL(300) > execute dbms_stats.set_global_prefs('trace',to_char(1+4+16+2048+65536));
SQL(300) > select sname, sval2, spare4 from sys.optstat_hist_control$ where sname in ('TRACE');
SNAME SVAL2 SPARE4
---------- ------------------------------ ------
TRACE 2018-JUN-29 12:10:36 +02:00 67605
SQL(300) > drop table test_tab;
SQL(300) > create table test_tab as select level x, mod(level, 4) y from dual connect by level <= 4321;
DBMS_STATS: postprocess_stats on KS.TEST_TAB.. tobjn: 2585597 fobjn:
DBMS_STATS: postprocess online optimizer stats gathering for KS.TEST_TAB: save statistics
5. Deadlock
There exist one background MMON Slave Process (Mnnn, for instance, M002), which is periodically (each 15 minutes in default) spawned to update Online Statistics (Flush KSXM hash table action). If coincidentally one foreground User session performs an IAS or CTAS operation at the same time, it can cause some deadlock as follows (some text removed):
Deadlock graph:
---------Blocker(s)-------- ---------Waiter(s)---------
Resource Name process session holds waits process session holds waits
TX-001F0003 123 321 X 789 987 S
TX-004C0008 789 987 X 123 321 X
Rows waited on:
Session 321: obj - rowid = 00000001
(dictionary objn - 1, file - 51, block - 2012345, slot - 0)
Session 987: no row
----- Information for the OTHER waiting sessions -----
Session 987:
sid: 987 ser: 9876 audsid: 0 user: 0/SYS
image: oracle@testdb (M002)
current SQL:
merge /*+ dynamic_sampling(mm 4) dynamic_sampling_est_cdn(mm) dynamic_sampling(m 4) dynamic_sampling_est_cdn(m) */ into sys.mon_mods_all$ mm
Information for THIS session:
----- Current SQL Statement for this session (sql_id=cyz7q9n00p23a) -----
update optstat_hist_control$ set sval2 = systimestamp where sname = 'MON_MODS_ALL_UPD_TIME'
alter system set events 'sql_trace [sql:5vf82wpjq5y0v] wait=true, bind=true,plan_stat=first_execution,level=12';
alter system set events 'sql_trace [sql:cyz7q9n00p23a] wait=true, bind=true,plan_stat=first_execution,level=12';
alter system set events 'sql_trace [sql:aahsjvcnr3swn] wait=true, bind=true,plan_stat=first_execution,level=12';
Unix process pid: 123, image: oracle@testdb (M002)
*** ACTION NAME:(Flush KSXM hash table action) 2018-06-26 11:15:27.632
===================== sql_id=5vf82wpjq5y0v
select null from optstat_hist_control$
where sname = 'MON_MODS_ALL_UPD_TIME'
and ((systimestamp - sval2) > INTERVAL '540' SECOND or sval2 is null)
for update
===================== sql_id=aahsjvcnr3swn
merge /*+ dynamic_sampling(mm 4) dynamic_sampling_est_cdn(mm) ynamic_sampling(m 4) dynamic_sampling_est_cdn(m) */
into sys.mon_mods_all$ mm
===================== sql_id=cyz7q9n00p23a
update optstat_hist_control$
set sval2 = systimestamp where sname = 'MON_MODS_ALL_UPD_TIME'
Unix process pid: 456, image: oracle@testdb
===================== sql_id=aahsjvcnr3swn
merge /*+ dynamic_sampling(mm 4) dynamic_sampling_est_cdn(mm) ynamic_sampling(m 4) dynamic_sampling_est_cdn(m) */
into sys.mon_mods_all$ mm
===================== sql_id=cyz7q9n00p23a
update optstat_hist_control$
set sval2 = systimestamp where sname = 'MON_MODS_ALL_UPD_TIME'
select from optstat_hist_control$ for update merge into sys.mon_mods_all$ update optstat_hist_control$whereas User session executes:
merge into sys.mon_mods_all$ update optstat_hist_control$The interleaved DML calls on mon_mods_all$ and optstat_hist_control$ probably caused the deadlock.
For all ORA-00060, the trace file is printed with following notice:
The following deadlock is not an ORACLE error. It is a deadlock due to user error in the design of an application or from issuing incorrect ad-hoc SQL. The following information may aid in determining the deadlock:In this case, the standard message is probably not addressed to application users.
Oracle has a hidden parameter (existed already in Oracle 11g):
_dml_monitoring_enabled
The workaround could be:
alter system set "_dml_monitoring_enabled"=false;
dml monitoring is happens even with _dml_monitoring_enabled set to false
and futher Workaround is:
statistics_level=basic
select sql_id, executions, last_active_time, first_load_time, sql_text
from v$sql v
where sql_id in ('5vf82wpjq5y0v', 'cyz7q9n00p23a', 'aahsjvcnr3swn')
order by v.last_active_time desc;
6. Appendix: sql_fulltext
Here the complete sqltext of above involved statements:
--sql_id=5vf82wpjq5y0v
select null
from optstat_hist_control$
where sname = 'MON_MODS_ALL_UPD_TIME'
and ( (systimestamp - sval2) > interval '540' second or sval2 is null)
for update
--sql_id=cyz7q9n00p23a
update sys.optstat_hist_control$ set sval2 = systimestamp where sname = 'MON_MODS_ALL_UPD_TIME';
--sql_id=aahsjvcnr3swn (M002)
merge /*+ dynamic_sampling(mm 4) dynamic_sampling_est_cdn(mm) dynamic_sampling(m 4) dynamic_sampling_est_cdn(m) */
into sys.mon_mods_all$ mm
using (select m.obj# obj#,
m.inserts inserts,
m.updates updates,
m.deletes deletes,
m.flags flags,
m.timestamp timestamp,
m.drop_segments drop_segments
from sys.mon_mods$ m, tab$ t
where m.obj# = t.obj# and :objn = 0
union all
select m.obj# obj#,
m.inserts inserts,
m.updates updates,
m.deletes deletes,
m.flags flags,
m.timestamp timestamp,
m.drop_segments drop_segments
from sys.mon_mods$ m, tab$ t
where m.obj# = t.obj# and :objn > 0 and m.obj# = :objn) v
on (mm.obj# = v.obj#)
when matched
then
update set mm.inserts = mm.inserts + v.inserts,
mm.updates = mm.updates + v.updates,
mm.deletes = mm.deletes + v.deletes,
mm.flags = mm.flags + v.flags - bitand (mm.flags, v.flags) /* bitor(mm.flags,v.flags) */,
mm.timestamp = v.timestamp,
mm.drop_segments = mm.drop_segments + v.drop_segments
when not matched
then
insert (obj#,
inserts,
updates,
deletes,
timestamp,
flags,
drop_segments)
values (v.obj#,
v.inserts,
v.updates,
v.deletes,
sysdate,
v.flags,
v.drop_segments);
