From oracle-l-bounce@freelists.org Fri Nov 19 03:24:44 2004 Return-Path: Received: from air189.startdedicated.com (root@localhost) by orafaq.com (8.11.6/8.11.6) with ESMTP id iAJ9Oi613969 for ; Fri, 19 Nov 2004 03:24:44 -0600 X-ClientAddr: 206.53.239.180 Received: from turing.freelists.org (freelists-180.iquest.net [206.53.239.180]) by air189.startdedicated.com (8.11.6/8.11.6) with ESMTP id iAJ9Odi13937 for ; Fri, 19 Nov 2004 03:24:39 -0600 Received: from localhost (localhost [127.0.0.1]) by turing.freelists.org (Avenir Technologies Mail Multiplex) with ESMTP id 5182072C81B; Fri, 19 Nov 2004 04:29:32 -0500 (EST) Received: from turing.freelists.org ([127.0.0.1]) by localhost (turing [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id 20468-77; Fri, 19 Nov 2004 04:29:31 -0500 (EST) Received: from turing (localhost [127.0.0.1]) by turing.freelists.org (Avenir Technologies Mail Multiplex) with ESMTP id 1190972DF21; Fri, 19 Nov 2004 04:26:50 -0500 (EST) Comment: DomainKeys? See http://antispam.yahoo.com/domainkeys DomainKey-Signature: a=rsa-sha1; q=dns; c=nofws; s=s1024; d=yahoo.com; b=vDecyVKdPrrg07e/8U0QTuSHm32NBRE/W9/Dgwuoz8WwBkN19JWjg8n5LtnDlVGqY+CaVASDw6Rm1NZ2LF3EAUCSVgkNjgzGxuZyrzQulUWoef/hTHlkwKDXo+X+LwxVky35pGHtXTEnjOCo96BuhUU22W/jzPHUtk9oZA5FXM4= ; Message-ID: <20041119092345.69634.qmail@web52607.mail.yahoo.com> Date: Fri, 19 Nov 2004 01:23:45 -0800 (PST) From: Martic Zoran Subject: Bulk (array) inserts - performances To: oracle-l@freelists.org MIME-Version: 1.0 Content-type: text/plain; charset=us-ascii Content-Transfer-Encoding: 8bit X-archive-position: 12425 X-ecartis-version: Ecartis v1.0.0 Sender: oracle-l-bounce@freelists.org Errors-To: oracle-l-bounce@freelists.org X-original-sender: zoran_martic@yahoo.com Precedence: normal Reply-To: zoran_martic@yahoo.com X-list: oracle-l X-Virus-Scanned: by amavisd-new at freelists.org Hi all, I have a few questions about bulk (array) inserts. The question is very simple and it is based on real scenario: 1. Do the bulk inserts from C-OCI 50 times per 100 inserts in the batch without duplicates 2. Do the same bulk inserts from C-OCI 50 times per 100 inserts in the batch. All inserts will fail because of PK and UK I have on the table. Both 1. and 2. are done on the same connection one after the other. First run took less then a second. The second took around 6 seconds. It is very easy to see Oracle db CPU statistics and other stats below. If the difference was not that big and the customers did not complain I will never realize that big discrepancy. This is not usually happening but when happens you do not want to have the system slowing that much. The questions are: 1) Why failing bulk inserts are that much slower then the bulk inserts without errors? Are the failing bulk inserts tend to have the similar characteristics as individual failing inserts? 2) Why the redo generated in the second run is much bigger? Is it the main reason for this slowness (I know there are a few, like sending the constraint name and error message, ...)? Any comments are welcome. When I did the run 2. without bulk operations just with simple failing inserts then redo generation was alsmot 6 times less then with bulk one :) Also, we all know that Oracle is always optimized for transactions that are going to happen more often then the others (like successful insert should be faster then unsuccessful one, ...). But again would like to know about bulk/array insert internals if possible :) These are all statistics I have got (the db is 9.2.0.6): NAME RUN1 RUN2 DIFF ---------------------------------------- -------------------- -------------------- -------------------- STAT...opened cursors current 1 0 -1 STAT...parse count (hard) 2 1 -1 STAT...redo ordering marks 0 1 1 STAT...commit cleanout failures: callbac 2 0 -2 STAT...redo buffer allocation retries 0 2 2 STAT...redo log space requests 0 2 2 STAT...OS System call CPU time 2 15 13 STAT...leaf node 90-10 splits 13 0 -13 STAT...physical reads 18 0 -18 STAT...redo log space wait time 0 19 19 STAT...leaf node splits 30 0 -30 STAT...redo synch time 33 1 -32 STAT...OS Output blocks 36 0 -36 STAT...calls to kcmgcs 39 3 -36 STAT...OS Wait-cpu (latency) time 2 40 38 STAT...commit txn count during cleanout 46 2 -44 STAT...redo synch writes 51 1 -50 STAT...user commits 51 1 -50 STAT...active txn count during cleanout 57 3 -54 STAT...OS Voluntary context switches 165 109 -56 STAT...change write time 1 58 57 STAT...immediate (CURRENT) block cleanou 77 13 -64 STAT...parse time cpu 1 68 67 STAT...cleanout - number of ktugct calls 73 4 -69 STAT...parse time elapsed 1 73 72 STAT...messages sent 51 125 74 STAT...calls to kcmgas 81 2 -79 STAT...free buffer requested 167 88 -79 STAT...deferred (CURRENT) block cleanout 135 2 -133 STAT...enqueue requests 161 7 -154 STAT...enqueue releases 161 5 -156 STAT...recursive cpu usage 1 247 246 STAT...commit cleanouts successfully com 278 3 -275 STAT...commit cleanouts 280 3 -277 STAT...bytes received via SQL*Net from c 331103 330653 -450 STAT...OS All other sleep time 359 834 475 STAT...OS User level CPU time 35 524 489 STAT...OS Involuntary context switches 64 574 510 STAT...CPU used by this session 31 552 521 STAT...CPU used when call started 31 552 521 STAT...calls to get snapshot scn: kcmgss 303 5061 4758 STAT...rows fetched via callback 2 5000 4998 STAT...execute count 54 5053 4999 STAT...opened cursors cumulative 4 5003 4999 STAT...parse count (total) 4 5003 4999 STAT...cluster key scan block gets 0 5000 5000 STAT...cluster key scans 0 5000 5000 STAT...index scans kdiixs1 0 5001 5001 STAT...shared hash latch upgrades - no w 0 5001 5001 STAT...rollback changes - undo records a 0 5001 5001 STAT...index fetch by key 2 10000 9998 STAT...table fetch by rowid 4 10003 9999 STAT...no work - consistent read gets 2 10004 10002 STAT...redo entries 851 16706 15855 STAT...consistent gets - examination 80 25004 24924 STAT...buffer is not pinned count 8 25007 24999 STAT...db block changes 1441 31713 30272 STAT...consistent gets 187 40014 39827 STAT...recursive calls 84 40016 39932 STAT...db block gets 1475 46820 45345 STAT...session logical reads 1662 86834 85172 STAT...session pga memory max 164568 65536 -99032 STAT...OS Process heap size 147456 32768 -114688 STAT...OS Chars read and written 621394 736368 114974 STAT...OS System calls 1509 119423 117914 STAT...session pga memory 164568 34096 -130472 STAT...bytes sent via SQL*Net to client 6987 356537 349550 STAT...redo size 1231360 18787720 17556360 Regards, Zoran Martic __________________________________ Do you Yahoo!? The all-new My Yahoo! - Get yours free! http://my.yahoo.com -- http://www.freelists.org/webpage/oracle-l