Re: Insert running long

  • From: Jonathan Lewis <jonathan@xxxxxxxxxxxxxxxxxx>
  • To: Oracle L <oracle-l@xxxxxxxxxxxxx>
  • Date: Fri, 3 Apr 2020 07:39:31 +0000


To calculate disk reads and buffer gets per row are you taking a couple of 
snapshots a couple of minutes apart and finding the difference; or just looking 
at the current valuese ?

The figures are very high, but if you've just taken a snapshot it may be 
because a cursor has been partially flushed and you could be looking at a 
running total where some stats are since first load and some are only for most 
recent reloads.

If the numbers are really what's going on there are two main possibilities
a) something about the inserts is making Oracle read a lot of undo records for 
each insert
b) there's a lot of leaf-blocks in the index that Oracle thinks are "empty" 
which turn out to be unusable when Oracle wants to do a leaf block split and 
find an empty block, and the search is doing a lot of work.

A (delta) snapshot the session stats that's doing a lot inserts would help 
identify what type of activity those block accesses are about.

The segstat figures look like roughly 4 buffer gets per block change (which 
looks about right for basic index inserts) and one physical read per block 
change (which looks like very randomly positioned inserts).  The 
clustering_factor of the index doesn't tell us a great deal, but it is very 
close to the rowcount, so may be a hint that the inserts are very widely 
scattered. With only 3.3M distinct keys and 2.5B rows that's an average of 750 
rpws per key, so your index is probably running at about 50% space utilisation 
which may explain the 92GB vs. 70GB (having done lots of 50/50 leaf block 
splits).   What's the avg_col_len and num_nulls of the column, by the way.

What can you tell us about the column that's indexed in terms of what the table 
represents and what the column means.


Regards
Jonathan Lewis


________________________________________
From: Bhavani Dhulipalla <bhavanidba6@xxxxxxxxx>
Sent: 02 April 2020 22:24
To: Jonathan Lewis
Cc: Oracle L
Subject: Re: Insert running long

Thank you Jonathan - Please find below


So, how many indexes have to be maintained as a row is inserted.


We have 5 indexes on the table and table has 2.6 B rows and it is 
Paritioned.one index is local and 4 are global and index 
UM_DWH_NXT.XIF3MEMBER_BANK_BALANCE is Global. Each Index Blevel is 3


Will any (many) of the indexes find that 400 rows inserted turns into 400 
different leaf blocks being updated?


I am not sure how to find this but I have put statistics of the Index from  the 
dba_hist_seg_stat below


How many buffer gets per row, disk_reads per row.


From gv$sql , Buffer gets per row is 3131 and disk_reads per row is 198.


Is there any reason why index UM_DWH_NXT.XIF3MEMBER_BANK_BALANCE stands out so 
much?


I am not sure , this index is 92GB while other indexes are 70GB , all are 
single column indexes. Below is information about this Index


INDEX_TYPE      BLEVEL LEAF_BLOCKS DISTINCT_KEYS CLUSTERING_FACTOR STATUS       
  NUM_ROWS_FROM_TABLE

------------ ---------- ----------- ------------- ----------------- -------- 
---------------

NORMAL               3   11371694      3378432       2216919296 VALID        
2643162455


what does v$segstat tell you about the work done on that index in an interval?


dhulipa@ebisprd2>select /*+ parallel(8) */ 
snap_id,LOGICAL_READS_DELTA,DB_BLOCK_CHANGES_DELTA,PHYSICAL_READS_DELTA,PHYSICAL_WRITES_DELTA,

 2 SPACE_USED_DELTA,PHYSICAL_READ_REQUESTS_DELTA,PHYSICAL_WRITE_REQUESTS_DELTA

 3 from dba_hist_seg_stat

 4 where snap_id between 97106 and 97117

 5 and OBJ#=215163

 6 ORDER BY SNAP_ID

 7 /



 SNAP_ID LOGICAL_READS_DELTA DB_BLOCK_CHANGES_DELTA PHYSICAL_READS_DELTA 
PHYSICAL_WRITES_DELTA SPACE_USED_DELTA PHYSICAL_READ_REQUESTS_DELTA 
PHYSICAL_WRITE_REQUESTS_DELTA

--------- ------------------- ---------------------- -------------------- 
--------------------- ---------------- ---------------------------- 
-----------------------------

   97107             101376                 28304               32271           
     17558         3095100                       32271                        
14983

   97108             236880                 64848               64368           
     54818         2096742                       64368                        
48919

   97109             358400                 98240               88657           
     80712         5438670                       88657                        
69689

   97110             394416                108432               95699           
     93032         5502702                       95699                        
81243

   97111             480544                132032              113761           
    112782         5261164                      113761                        
96141

   97112             585520                160768              137968           
    139199         8704388                      137968                       
116044

   97113             714592                196096              166009           
    164001         8041066                      166009                       
135602

   97114            1003936                275968              229062           
    221835        14961466                      229062                       
173816

   97115            1399760                384512              315269           
    324627        18910386                      315269                       
218620

   97116            1755744                482192              394582           
    399826        24212094                      394582                       
258966

   97117            2028272                556176              445315           
    559226        27080352                      445315                       
448986

On Thu, Apr 2, 2020 at 3:39 PM Jonathan Lewis 
<jonathan@xxxxxxxxxxxxxxxxxx<mailto:jonathan@xxxxxxxxxxxxxxxxxx>> wrote:
400 rows inserted per call, 1.5 seconds per call.
Now you need to decide if that's reasonable or not.

So, how many indexes have to be maintained as a row is inserted.
Will any (many) of the indexes find that 400 rows inserted turns into 400 
different leaf blocks being updated.

How many buffer gets per row, disk_reads per row.

Is there any reason why index UM_DWH_NXT.XIF3MEMBER_BANK_BALANCE stands out so 
much - what does v$segstat tell you about the work done on that index in an 
interval. Does the size of the index look unreasonable large for the number of 
entries it should hold .... etc.


Regards
Jonathan Lewis


________________________________________
From: Bhavani Dhulipalla <bhavanidba6@xxxxxxxxx<mailto:bhavanidba6@xxxxxxxxx>>
Sent: 02 April 2020 18:43
To: Jonathan Lewis
Cc: oracle-l@xxxxxxxxxxxxx<mailto:oracle-l@xxxxxxxxxxxxx>
Subject: Re: Insert running long

Hi Jonathan

it seems like 400 is the array size and I see that query got executed many more 
times today than previous . Each execution is taking 1.5 sec avg

bdhulipa@ebisprd2>select 21984327/54964 from dual;399.976839

bdhulipa@ebisprd2>select 3769805/9425 from dual;
399.97931

select trunc(cast(BEGIN_INTERVAL_TIME as date)),sum(executions_delta)
from
dba_hist_snapshot sn
, dba_hist_sqlstat st
WHERE
sn.snap_id = st.snap_id
AND sn.dbid = st.dbid
AND sn.instance_number = st.instance_number
AND sql_id = 'aqs7g5aj9s44d'
GROUP BY
trunc(cast(BEGIN_INTERVAL_TIME as date))
order by 1
/Date SUM(EXECUTIONS_DELTA)
------------------ ---------------------
03-MAR-20 00:00:00 10367
04-MAR-20 00:00:00 10479
05-MAR-20 00:00:00 10461
06-MAR-20 00:00:00 10434
07-MAR-20 00:00:00 10418
10-MAR-20 00:00:00 10405
11-MAR-20 00:00:00 10379
12-MAR-20 00:00:00 10294
13-MAR-20 00:00:00 10280
14-MAR-20 00:00:00 10307
17-MAR-20 00:00:00 10354
18-MAR-20 00:00:00 10400
19-MAR-20 00:00:00 10429
20-MAR-20 00:00:00 10481
21-MAR-20 00:00:00 10541
24-MAR-20 00:00:00 10606
25-MAR-20 00:00:00 10640
26-MAR-20 00:00:00 10643
27-MAR-20 00:00:00 10674
28-MAR-20 00:00:00 10717
31-MAR-20 00:00:00 10807
01-APR-20 00:00:00 10862
02-APR-20 00:00:00 10964

[image.png]

On Thu, Apr 2, 2020 at 1:17 PM Jonathan Lewis 
<jonathan@xxxxxxxxxxxxxxxxxx<mailto:jonathan@xxxxxxxxxxxxxxxxxx><mailto:jonathan@xxxxxxxxxxxxxxxxxx<mailto:jonathan@xxxxxxxxxxxxxxxxxx>>>
 wrote:

If you want to check whether that statement is using single row processing or 
array processing then select executions, and rows_processed from v$sql for the 
SQL_ID.
Do it a couple of times over a few minutes and the deltas should allow you to 
work out the arraysize (with a little error, possibly).

Regards
Jonathan Lewis



________________________________________
From: 
oracle-l-bounce@xxxxxxxxxxxxx<mailto:oracle-l-bounce@xxxxxxxxxxxxx><mailto:oracle-l-bounce@xxxxxxxxxxxxx<mailto:oracle-l-bounce@xxxxxxxxxxxxx>>
 
<oracle-l-bounce@xxxxxxxxxxxxx<mailto:oracle-l-bounce@xxxxxxxxxxxxx><mailto:oracle-l-bounce@xxxxxxxxxxxxx<mailto:oracle-l-bounce@xxxxxxxxxxxxx>>>
 on behalf of Bhavani Dhulipalla 
<bhavanidba6@xxxxxxxxx<mailto:bhavanidba6@xxxxxxxxx><mailto:bhavanidba6@xxxxxxxxx<mailto:bhavanidba6@xxxxxxxxx>>>
Sent: 02 April 2020 18:04
To: 
oracle-l@xxxxxxxxxxxxx<mailto:oracle-l@xxxxxxxxxxxxx><mailto:oracle-l@xxxxxxxxxxxxx<mailto:oracle-l@xxxxxxxxxxxxx>>
Subject: Insert running long

Hello



DB Version 11.2.0.4 OS Linux


one of the insert process is running from 6 hours today and getting executed so 
many times - Each Execution is roughly taking a sec -

its plain insert -I suspect it is is being done in pl/sql loop row by row 
processing -

How can I validate it ? ask for the pl/sql procedure and check the code -

this is the insert query -


INSERT INTO MEMBER_BANK_BAL(MEMBER_BANK_BAL_ID,MEM

BER_BANK_ID,INTERNAL_ACCT_ID,MEMBER_BANK_BAL_AMT,A

CCRUED_INT_AMT,FROM_DT,TO_DT,CREATE_TS,LAST_UPDT_T

S,RT_RECRD_NUM,RT_TIER_BAL,BATCH_JOB_EXECUTION_ID)

VALUES ( :1, :2, :3, :4, :5, :6, :7, :8, :9, :10

, :11, :12)


Wait events:


bdhulipa@ebisprd2>@ash/ashtop event2 sql_id='aqs7g5aj9s44d' sysdate-4/24 sysdate


Total Distinct

Seconds AAS %This EVENT2 FIRST_SEEN LAST_SEEN Execs Seen

--------- ------- ------- ------------------------------------------ 
------------------- ------------------- ----------

14192 1.0 99% | db file sequential read 2020-04-02 04:40:04 2020-04-02 08:40:03 
6352

149 .0 1% | ON CPU 2020-04-02 04:41:51 2020-04-02 08:39:30 149

2 .0 0% | enq: FB - contention [mode=6] 2020-04-02 04:51:41 2020-04-02 07:34:04 
2

2 .0 0% | gc current multi block request 2020-04-02 08:15:22 2020-04-02 
08:15:29 2

1 .0 0% | gc current block 2-way 2020-04-02 07:44:19 2020-04-02 07:44:19 1

1 .0 0% | gc current grant 2-way 2020-04-02 06:32:56 2020-04-02 06:32:56 1

1 .0 0% | local write wait 2020-04-02 08:37:47 2020-04-02 08:37:47 1


It seems like db file sequential reads are generating from Index


bdhulipa@ebisprd2>@ash/ashtop objt "sql_id='aqs7g5aj9s44d' and event2='db file 
sequential read'" sysdate-4/24 sysdate


Total Distinct

Seconds AAS %This OBJT FIRST_SEEN LAST_SEEN Execs Seen

--------- ------- ------- -------------------------------------------------- 
------------------- ------------------- ----------

13854 1.0 100% | UM_DWH_NXT.XIF3MEMBER_BANK_BALANCE [INDEX] 2020-04-02 05:24:16 
2020-04-02 09:19:46 8054

4 .0 0% | UM_DWH_NXT.XIF5MEMBER_BANK_BALANCE [INDEX] 2020-04-02 06:22:53 
2020-04-02 07:06:51 4

3 .0 0% | UM_DWH_NXT.XPKMEMBER_BANK_BALANCE [INDEX] 2020-04-02 07:12:04 
2020-04-02 07:26:29 3



Thanks

Bhavani
--
//www.freelists.org/webpage/oracle-l


--
//www.freelists.org/webpage/oracle-l


Other related posts: