Not a coincidence. See Optimizing Oracle Performance, Chapter 12, "Case 3: Large SQL*Net Event Duration" on pages 337-344. See also the SQL*Net material on pp311-315.
Cary Millsap Hotsos Enterprises, Ltd. http://www.hotsos.com Upcoming events: - Performance Diagnosis 101: 11/19 Sydney, 12/16 Detroit - SQL Optimization 101: 12/8 Dallas, 2/16 Dallas - Hotsos Symposium 2004: March 7-10 Dallas - Visit www.hotsos.com for schedule details... -----Original Message----- Barbara Baker Sent: Thursday, November 13, 2003 9:09 AM To: Multiple recipients of list ORACLE-L List: My apologies. Seems like I'm taking up more than my share of bandwith. I'm doing major battle with a vendor. Their app runs this "thing" that takes 10 seconds. Unfortunately it runs this thing several thousand times a day. This is a critical issue for us. I trapped what's running in that 10 seconds. The code looks just swell. Seems pretty obvious to me that the problem is with the large number of parses occurring. I see 1 spot where they parse 5 times and return 0 rows; another where they parse, execute, and fetch 5 times for no obvious reason. We do not have access to the vendor code. The vendor says set cursor_sharing to "force". I say that's solving the wrong problem. First naive question: Without their code, is there any way for me to know what could cause this large number of parses? 2nd question: I see an exact match between the number of parses and the times waited on "sql*net message to client". Is this coincidence, or can I make some correlation here? Thanks so much for your patience and your help. Database is 8.1.7.4 on Solaris 8. Barb SELECT PAPER, PAGE, PAGENAME, PAGENO, COLUMNS, COLWIDTH, COLSPACE, HEIGHT FROM PAGE call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 2 0.02 0.02 0 0 0 0 Execute 1 0.00 0.00 0 0 0 0 Fetch 1 0.01 0.01 0 13 12 72 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 4 0.03 0.03 0 13 12 72 Misses in library cache during parse: 1 Optimizer goal: CHOOSE Parsing user id: 586 (SYSADMIN) Rows Execution Plan ------- --------------------------------------------------- 0 SELECT STATEMENT GOAL: CHOOSE 0 TABLE ACCESS GOAL: ANALYZED (FULL) OF 'PAGE' Elapsed times include waiting on following events: Event waited on Times Max. Wait Total Waited ---------------------------------------- Waited ---------- ------------ SQL*Net message to client 2 0.00 0.00 SQL*Net message from client 2 0.00 0.00 SQL*Net more data to client 1 0.00 0.00 ************************************************************************ ******** SELECT PAPER, PAGE, PAGENAME, PAGENO, COLUMNS, COLWIDTH, COLSPACE, HEIGHT FROM PAGE WHERE PAPER = :1 AND PAGE = :2 call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 2 0.00 0.01 0 0 0 0 Execute 1 0.00 0.00 0 0 0 0 Fetch 1 0.00 0.00 0 2 0 1 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 4 0.00 0.01 0 2 0 1 Misses in library cache during parse: 1 Parsing user id: 586 (SYSADMIN) Rows Execution Plan ------- --------------------------------------------------- 0 SELECT STATEMENT GOAL: CHOOSE 0 TABLE ACCESS GOAL: ANALYZED (BY INDEX ROWID) OF 'PAGE' 0 INDEX GOAL: ANALYZED (UNIQUE SCAN) OF 'I_PAG1' (UNIQUE) Elapsed times include waiting on following events: Event waited on Times Max. Wait Total Waited ---------------------------------------- Waited ---------- ------------ SQL*Net message to client 2 0.00 0.00 SQL*Net message from client 2 0.09 0.09 ************************************************************************ ******** SELECT HID, PARENT, CHILD, NODE_TYPE, NODE_ITEM, TAG, ATTRIBUTE_ITEM FROM XMLS_HIERARCHY WHERE HID = :1 call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 5 0.00 0.00 0 0 0 0 Execute 0 0.00 0.00 0 0 0 0 Fetch 0 0.00 0.00 0 0 0 0 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 5 0.00 0.00 0 0 0 0 Misses in library cache during parse: 1 Parsing user id: 586 (SYSADMIN) Rows Execution Plan ------- --------------------------------------------------- 0 SELECT STATEMENT GOAL: CHOOSE 0 TABLE ACCESS GOAL: ANALYZED (BY INDEX ROWID) OF 'XMLS_HIERARCHY' 0 INDEX GOAL: ANALYZED (UNIQUE SCAN) OF 'PK_XMLS_HIERARCHY' (UNIQUE) Elapsed times include waiting on following events: Event waited on Times Max. Wait Total Waited ---------------------------------------- Waited ---------- ------------ SQL*Net message to client 5 0.00 0.00 SQL*Net message from client 5 0.01 0.01 ************************************************************************ ******** SELECT HID , PARENT , CHILD , NODE_TYPE , NODE_ITEM , TAG , ATTRIBUTE_ITEM , XMLS_HIERARCHY."ROWID" FROM XMLS_HIERARCHY WHERE HID = :1 call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 5 0.00 0.00 0 0 0 0 Execute 5 0.01 0.00 0 0 0 0 Fetch 5 0.00 0.00 0 10 0 5 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 15 0.01 0.00 0 10 0 5 Misses in library cache during parse: 1 Optimizer goal: CHOOSE Parsing user id: 586 (SYSADMIN) Rows Row Source Operation ------- --------------------------------------------------- 1 TABLE ACCESS BY INDEX ROWID XMLS_HIERARCHY 2 INDEX UNIQUE SCAN (object id 394972) Rows Execution Plan ------- --------------------------------------------------- 0 SELECT STATEMENT GOAL: CHOOSE 1 TABLE ACCESS GOAL: ANALYZED (BY INDEX ROWID) OF 'XMLS_HIERARCHY' 2 INDEX GOAL: ANALYZED (UNIQUE SCAN) OF 'PK_XMLS_HIERARCHY' (UNIQUE) Elapsed times include waiting on following events: Event waited on Times Max. Wait Total Waited ---------------------------------------- Waited ---------- ------------ SQL*Net message to client 5 0.00 0.00 SQL*Net message from client 4 1.39 4.63 ************************************************************************ ******** OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 14 0.02 0.03 0 0 0 0 Execute 7 0.01 0.00 0 0 0 0 Fetch 7 0.01 0.01 0 25 12 78 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 28 0.04 0.04 0 25 12 78 Misses in library cache during parse: 4 Elapsed times include waiting on following events: Event waited on Times Max. Wait Total Waited ---------------------------------------- Waited ---------- ------------ SQL*Net message to client 14 0.00 0.00 SQL*Net message from client 13 1.39 4.73 SQL*Net more data to client 1 0.00 0.00 __________________________________ Do you Yahoo!? Protect your identity with Yahoo! Mail AddressGuard http://antispam.yahoo.com/whatsnewfree -- Please see the official ORACLE-L FAQ: http://www.orafaq.net -- Author: Barbara Baker INET: [EMAIL PROTECTED] Fat City Network Services -- 858-538-5051 http://www.fatcity.com San Diego, California -- Mailing list and web hosting services --------------------------------------------------------------------- To REMOVE yourself from this mailing list, send an E-Mail message to: [EMAIL PROTECTED] (note EXACT spelling of 'ListGuru') and in the message BODY, include a line containing: UNSUB ORACLE-L (or the name of mailing list you want to be removed from). You may also send the HELP command for other information (like subscribing). -- Please see the official ORACLE-L FAQ: http://www.orafaq.net -- Author: Cary Millsap INET: [EMAIL PROTECTED] Fat City Network Services -- 858-538-5051 http://www.fatcity.com San Diego, California -- Mailing list and web hosting services --------------------------------------------------------------------- To REMOVE yourself from this mailing list, send an E-Mail message to: [EMAIL PROTECTED] (note EXACT spelling of 'ListGuru') and in the message BODY, include a line containing: UNSUB ORACLE-L (or the name of mailing list you want to be removed from). You may also send the HELP command for other information (like subscribing).
