Re: Insert running long
From: Jonathan Lewis <jonathan_at_jlcomp.demon.co.uk>
Date: Fri, 3 Apr 2020 07:49:10 +0000
Message-ID: <LNXP265MB15624DE607312BBEE83043B8A5C70_at_LNXP265MB1562.GBRP265.PROD.OUTLOOK.COM>
Date: Fri, 3 Apr 2020 07:49:10 +0000
Message-ID: <LNXP265MB15624DE607312BBEE83043B8A5C70_at_LNXP265MB1562.GBRP265.PROD.OUTLOOK.COM>
I see yo've also posted this to the ODC developer forum. The buffer gets and disk reads you've reported are per execution, not per row >> From gv$sql , Buffer gets per row is 3131 and disk_reads per row is 198. At 400 rows per execution this means it's more like 8 buffer gets per row and 0.5 disk reads per row. Which means it's most likely about the basic effect of a large index with very scattered inserts. Regards Jonathan Lewis ________________________________________ From: Bhavani Dhulipalla <bhavanidba6_at_gmail.com> 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_at_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_at_jlcomp.demon.co.uk<mailto:jonathan_at_jlcomp.demon.co.uk>> 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_at_gmail.com<mailto:bhavanidba6_at_gmail.com>> Sent: 02 April 2020 18:43 To: Jonathan Lewis Cc: oracle-l_at_freelists.org<mailto:oracle-l_at_freelists.org> 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_at_ebisprd2>select 21984327/54964 from dual;399.976839 bdhulipa_at_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_at_jlcomp.demon.co.uk<mailto:jonathan_at_jlcomp.demon.co.uk><mailto:jonathan_at_jlcomp.demon.co.uk<mailto:jonathan_at_jlcomp.demon.co.uk>>> 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_at_freelists.org<mailto:oracle-l-bounce_at_freelists.org><mailto:oracle-l-bounce_at_freelists.org<mailto:oracle-l-bounce_at_freelists.org>> <oracle-l-bounce_at_freelists.org<mailto:oracle-l-bounce_at_freelists.org><mailto:oracle-l-bounce_at_freelists.org<mailto:oracle-l-bounce_at_freelists.org>>> on behalf of Bhavani Dhulipalla <bhavanidba6_at_gmail.com<mailto:bhavanidba6_at_gmail.com><mailto:bhavanidba6_at_gmail.com<mailto:bhavanidba6_at_gmail.com>>> Sent: 02 April 2020 18:04 To: oracle-l_at_freelists.org<mailto:oracle-l_at_freelists.org><mailto:oracle-l_at_freelists.org<mailto:oracle-l_at_freelists.org>> 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_at_ebisprd2>_at_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_at_ebisprd2>_at_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 -- http://www.freelists.org/webpage/oracle-l --http://www.freelists.org/webpage/oracle-l Received on Fri Apr 03 2020 - 09:49:10 CEST