I was really puzzled why performance for compressed tables was horrendous.
My knowledge of the environment enabled me to make a hypothesis on the cause for performance degradation-db_block_checking.
I agree with Martin Berger the finding was generally indirect and not sure how someone else would have been able to identify the issue.
Even Oracle Support suggested the only hint is increase CPU. However, there can be many factors affecting CPU, e.g. nested loop.
The database version is 11.2.0.3 running on Sparc Solaris 10 64bit
Setup:
FACT table COMPRESS FOR OLTP with DEFAULT PCTFREE, INITTRANS settings (53 cols NOT NULL)
PK (1 col)
AK (3 col)
IX (1 col)
33,179,386 rowsSTAGING table with DEFAULT PCTFREE, INITTRANS settings (52 cols, 1 col NOT NULL, remaining NULL)
No index/constraints
911,861 rowsPseudo Code:
MERGE INTO FACT f USING STAGING s ON (f.KEY=s.KEY)
WHEN MATCHED THEN UPDATE SET … 52 columnsSQL Script:
set timing on serveroutput on
spool testcomp.log
—
exec runstats_pkg.rs_start;
commit;
—
alter session force parallel dml parallel 8;
@/oracle/sqlt/input/sample/oltp_false.sql
alter session disable parallel dml;
—
exec runstats_pkg.rs_middle;
commit;
—
alter session force parallel dml parallel 8;
@/oracle/sqlt/input/sample/oltp_medium.sql
alter session disable parallel dml;
—
exec runstats_pkg.rs_stop(0,’WORKLOAD’);
exec runstats_pkg.rs_stop(1000000);
—
alter system set db_block_checking=FALSE;
spool off
SQL Execution Snipit:
SQL> alter system set db_block_checking=FALSE;
System altered.
Elapsed: 00:00:00.01
SQL> set echo off
911861 rows merged.
Elapsed: 00:01:52.30
Commit complete.
SQL> alter system set db_block_checking=MEDIUM;
System altered.
Elapsed: 00:00:00.01
SQL> set echo off
911861 rows merged.
Elapsed: 00:23:44.38
Commit complete.
Run1 ran in 11483 hsecs - db_block_checking=FALSE
Run2 ran in 142483 hsecs - db_block_checking=MEDIUM
run 1 ran in 8.06% of the time
Name Run1 Run2 Diff
STAT...physical reads direct 517,192 517,208 16
STAT...physical reads 522,167 517,224 -4,943
STAT...physical reads cache 4,975 16 -4,959
STAT...Elapsed Time 11,487 142,487 131,000
STAT...recursive cpu usage 34,909 498,166 463,257
STAT...CPU used by this session 35,572 498,920 463,348
STAT...redo size 889,907,464 892,430,032 2,522,568
STAT...session logical reads 3,480,123 6,557,752 3,077,629
Run1 latches total versus runs -- difference and pct
Run1 Run2 Diff Pct
20,508,977 68,940,229 48,431,252 29.75%
PL/SQL procedure successfully completed.
Elapsed: 00:00:00.08
Run1 ran in 11483 hsecs - db_block_checking=FALSE
Run2 ran in 142491 hsecs - db_block_checking=MEDIUM
run 1 ran in 8.06% of the time
Name Run1 Run2 Diff
STAT...session uga memory max 130,976 1,293,104 1,162,128
STAT...in call idle wait time 115,158 1,409,641 1,294,483
LATCH.simulator hash latch 247,055 1,556,432 1,309,377
LATCH.object queue header operation 205,535 1,766,312 1,560,777
STAT...session pga memory 851,968 -720,896 -1,572,864
LATCH.transaction allocation 108,304 1,936,419 1,828,115
STAT...DB time 189,534 2,196,702 2,007,168
STAT...redo size 889,907,464 892,433,832 2,526,368
LATCH.checkpoint queue latch 90,178 2,757,576 2,667,398
STAT...session logical reads 3,480,123 6,557,897 3,077,774
STAT...consistent gets 838,019 3,926,800 3,088,781
STAT...consistent gets from cache 20,153 3,109,037 3,088,884
STAT...consistent gets - examination 11,341 3,101,011 3,089,670
STAT...data blocks consistent reads -
undo records applied 0 3,091,383 3,091,383
STAT...Effective IO time 8,124,867 4,359,804 -3,765,063
LATCH.DML lock allocation 450,593 5,815,377 5,364,784
STAT...file io wait time 51,133,453 44,027,178 -7,106,275
LATCH.cache buffers chains 14,751,617 45,136,022 30,384,405
STAT...physical read bytes 8,555,184,128 8,474,198,016 -80,986,112
STAT...physical read total bytes 8,555,184,128 8,474,198,016 -80,986,112
STAT...cell physical IO interconnect byt 8,555,184,128 8,474,198,016 -80,986,112
STAT...logical read bytes from cache 43,618,418,688 94,044,405,760 50,425,987,072
Run1 latches total versus runs -- difference and pct
Run1 Run2 Diff Pct
41,017,954 137,883,083 96,865,129 29.75%
Run1 - blk_checking_false
Disk Reads 522,167
Buffer Gets 3,479,799
98% CPU Wait 1:60 (mm:ss)
Run2 - blk_checking_medium
Disk Reads 517,116
Buffer Gets 6,547,223
90% CPU Wait 21:08 (mm:ss)
Test shows db_block_checking and compression are bad for performance due to a bug.
Unfortunately, from the all the metrics I have looked at, there’s is not a direct indication to the cause.
Open to ideas as what to look for or what analysis can be performed.
I have used XTRACT, XECUTE, COMPARE, TRCANLZR from SQLTXPLAIN (SQLT) 11.4.5.2
References:
Notes with explanations for OLTP compression, db_block_checking, db_lost_write_protect.
Best Practices for Corruption Detection, Prevention, and Automatic Repair – in a Data Guard Configuration [ID 1302539.1]
Master Note for OLTP Compression [ID 1223705.1]
Bug 12711341: EXTREME SLOWNESS WITH DB_ULTRA_SAFE ON COMPRESSED TABLES
Customer is not happy with the performance of DML after enabling COMPRESS option and turning DB_BLOCK_CHECKING = FULL.
Bug 8931846: DB_BLOCK_CHECKING CAUSES LARGE PERFORMANCE HIT WITH COMPRESSED TABLE
Thinking Out Loud 