Applies to:
Oracle Database - Enterprise Edition - Version 10.2.0.1 to 12.1.0.2 [Release 10.2 to 12.1]Information in this document applies to any platform.
Symptoms
A single INSERT statement following a large batch INSERT is very
slow. The second execution of the same INSERT finishes immediately.
The 10046 trace file for the first single slow INSERT shows excessive waits on 'db file sequential read':
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
rdbms ipc reply 1 0.00 0.00
SQL*Net more data from client 2 0.00 0.00
db file sequential read 9670 0.02 13.73
db file scattered read 56 0.02 0.84
SQL*Net break/reset to client 1 0.00 0.00
The execution statistics show excessive values for 'db block gets':
----------------------------------------------------------
1 recursive calls
46272 db block gets
13 consistent gets
21101 physical reads
2937940 redo size
1123 bytes sent via SQL*Net to client
1631 bytes received via SQL*Net from client
4 SQL*Net roundtrips to/from client
1 sorts (memory)
0 sorts (disk)
1 rows processed
The statistics for the second execution of the same INSERT shows low values for 'db block gets':
----------------------------------------------------------
0 recursive calls
5 db block gets
1 consistent gets
1 physical reads
0 redo size
1134 bytes sent via SQL*Net to client
1631 bytes received via SQL*Net from client
4 SQL*Net roundtrips to/from client
1 sorts (memory)
0 sorts (disk)
1 rows processed
Using the DBMS_SPACE.UNUSED_SPACE as listed below shows that
the FS1 blocks before the first INSERT move to the FULL blocks following
the slow execution:
total_bl NUMBER;
total_by NUMBER;
unused_bl NUMBER;
unused_by NUMBER;
last_used_extent_file_id NUMBER;
last_used_extent_block_id NUMBER;
last_used_block NUMBER;
unformatted_blocks NUMBER;
unformatted_bytes NUMBER;
fs1_bl NUMBER;
fs1_by NUMBER;
fs2_bl NUMBER;
fs2_by NUMBER;
fs3_bl NUMBER;
fs3_by NUMBER;
fs4_bl NUMBER;
fs4_by NUMBER;
full_bl NUMBER;
full_by NUMBER;
i number;
BEGIN
dbms_space.unused_space('OWNER','TABLE NAME', 'TABLE',
total_bl , total_by , unused_bl , unused_by , last_used_extent_file_id , last_used_extent_block_id , last_used_block );
dbms_space.space_usage('OWNER','TABLE_NAME', 'TABLE',
unformatted_blocks , unformatted_bytes , fs1_bl , fs1_by , fs2_bl , fs2_by , fs3_bl , fs3_by , fs4_bl , fs4_by , full_bl , full_by );
dbms_output.put_line('| total_bl| total_by| unused_bl| unused_by| last_used_extent_file_id| last_used_extent_block_id| last_used_block');
dbms_output.put_line('| '||lpad(total_bl,8)||'|'||
lpad(total_by,9)||'|'||
lpad(unused_bl,10)||'|'||
lpad(unused_by,10)||'|'||
lpad(last_used_extent_file_id,25)||'|'||
lpad(last_used_extent_block_id,26)||'|'||
lpad(last_used_block,16));
dbms_output.put_line(' .');
dbms_output.put_line('| unformatted_blocks| unformatted_bytes| fs1_bl| fs1_by| fs2_bl| fs2_by| fs3_bl| fs3_by| fs4_bl| fs4_by| full_bl| full_by');
dbms_output.put_line('| '||lpad(unformatted_blocks,18)||'|'||
lpad(unformatted_bytes,18)||'|'||
lpad(fs1_bl,7)||'|'||
lpad(fs1_by,7)||'|'||
lpad(fs2_bl,7)||'|'||
lpad(fs2_by,7)||'|'||
lpad(fs3_bl,7)||'|'||
lpad(fs3_by,7)||'|'||
lpad(fs4_bl,7)||'|'||
lpad(fs4_by,7)||'|'||
lpad(full_bl,8)||'|'||
lpad(full_by,8));
end;
/
prompt FS1 means 0-25% free space within a block
prompt FS2 means 25-50% free space within a block
prompt FS3 means 50-75% free space within a block
prompt FS4 means 75-100% free space within a block
set serveroutput on
exec get_space_info;
When tracing the ASSM space allocation during the first single
slow INSERT using the following events, the FS1 blocks appear to be
marked as FULL:
SQL> ALTER SESSION SET EVENTS '10612 trace name context forever , level 1';
SQL> -- run the single INSERT
-- the trace file contains the following comments:
...
[ktspsrch] adddba dba:0x0100636b curl1:0x01006280 curl2:0x01002601
ktspfsrch: Returns: BlockDBA:0x0100637b
kdt_bseg_srch_cbk: examine dba=4.0x0100637b
kdt_bseg_srch_cbk: failed dba=4.0x0100637b avs=837 afs=0 tosp=837 full=1
ktspfupdst: state change tsn 4, objd 96400, objn 71401, blksz 8192
ktspfupdst: oldstate 2, newstate 1, delta bytes 1065
ktspfupdst: fdba: 0x01006280 offset: 251 nblks: 1 newstate: 1
kdt_bseg_srch_cbk: mark full --------------------------------------------------> the blocks is marked as full
ktspfsrch:Cbk didnot like 0x0100637b
...
Cause
This is the expected behavior
This is the same situation as in Bug 7411960 "A SIMPLE INSERT CAUSES LOTS OF 'DB FILE SEQUENTIAL READ' WAITS" and it
is the expected behavior. As per bug explanation, this is because there
are multiple blocks with insufficient space to store the new data and
Oracle needs to skip these blocks during the search for a good
candidate. Oracle has been trying to balance the performance versus
space management on ASSM segments. In this case, it seems Oracle
inclined over the space management and this caused to have multiple
blocks not marked as full, but not having enough space to accommodate
new rows. So, Oracle needs to read multiple blocks in order to find one
block with enough space to insert the new row.
This behavior also applies to higher versions like 11g.
Solution
The workaround is to manually mark these blocks as full and to increase the PCTFREE to a higher value in order to promote blocks to be marked as full in a better rate.
EXECUTE DBMS_REPAIR.SEGMENT_FIX_STATUS('','');