| Oracle FAQ | Your Portal to the Oracle Knowledge Grid | |
 |
 | |||
| Oracle FAQ | Your Portal to the Oracle Knowledge Grid | |
|
| |||
Home -> Community -> Mailing Lists -> Oracle-L -> PL/SQL Wrapper Costs
I was asked to look at performance on someone else's system, running
Oracle 10.1.0.4 under HPUX. Its actually a 2 node RAC cluster, but I
don't think thats all that important here.
This is an older commercial application, written using the (older) UNIFACE client-server framework, which appears to use a lot of PL/SQL procedures that essentially run a singleton select ... into statement, specifying the PK in the where clause. All input/output is done through individual bind variables. No dynamic SQL. There is not much logic within the procedures. User response time has been an issue. We ran 10046 traces files of known problem scenarios and formatted using tkprof as well as trace analyzer.
One thing that I noticed is that the elapsed time for the procedure call is 4-5X the elapsed time of the underlying query, which does not seem right to me. Is this expected for the overhead in calling a PL/SQL procedure and marshalling arguments in and out? Not much else is happening in the procedures.
Also, I'm just curious, does anyone really write applications this way
anymore?
It seems pretty inefficient to run a call for every record you need.
Lots of round trips on the network etc, especially for client server.
I did not see any other obvious issues in the trace file, other than
LOTS of procedure calls.
Any clues would be appreciated.
Oh, and these procedures typically get called many 1000s of times an hour. The trace file represents about 10 minutes of activity on a particular transaction in one session.
Here are some clips from the trace file:
*The procedure call:*
BEGIN "IDNT$U"."UNIFACE_IO"( :UNIFACE_IO_REQUEST, :XIDNT_ID, :XU_VERSION,
:XIDNT_XREF_ID, :XFOLDER_NBR, :XDETAINEE_ID, :XRECIDIVIST, :XPRFX_CD,
:XSFFX_CD, :XFIRST_NAME, :XMIDDLE_NAME, :XLAST_NAME, :XCOMPANY_NAME,
:XSSN,
:XDOB, :XDOD, :XBIRTH_CNTY_CD, :XBIRTH_CITY_CD, :XBIRTH_ST_CD, :XSECRET,
:XINS_BY, :XINS_PRG, :XINS_DTTM, :XUPD_BY, :XUPD_PRG, :XUPD_DTTM,
:XCITY_TEXT, :XCOUNTY_TEXT, :XDRIVERS_LIC_NO, :XSID, :XBCI, :XFBI,
:XFULL_NAME_SOUNDEX, :XROWID, :WIDNT_ID, :WU_VERSION,
:ONE_ROW_AFFECTED );
END;
call count cpu elapsed disk query current rows
Parse 3 0.00 0.00 0 0 0 0 Execute 1419 4.61 7.39 80 5676 0 1419 Fetch 0 0.00 0.00 0 0 0 0
total 1422 4.61 7.39 80 5676 0 1419
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 448
Elapsed times include waiting on following events:
Event waited on Times Max. Wait TotalWaited
*The select statement:*
SELECT /*+ FIRST_ROWS */ "IDNT_ID", "U_VERSION", "IDNT_XREF_ID",
"FOLDER_NBR",
"DETAINEE_ID", "RECIDIVIST", "PRFX_CD", "SFFX_CD", "FIRST_NAME",
"MIDDLE_NAME", "LAST_NAME", "COMPANY_NAME", "SSN", "DOB", "DOD", "BIRTH_CNTY_CD", "BIRTH_CITY_CD", "BIRTH_ST_CD", "SECRET", "INS_BY", "INS_PRG", "INS_DTTM", "UPD_BY", "UPD_PRG", "UPD_DTTM", "CITY_TEXT", "COUNTY_TEXT", "DRIVERS_LIC_NO", "SID", "BCI", "FBI", "FULL_NAME_SOUNDEX"FROM
call count cpu elapsed disk query current rows
Parse 8 0.00 0.00 0 0 0 0 Execute 1419 0.39 0.46 0 0 0 0 Fetch 1419 0.13 0.76 80 5676 0 1419
total 2846 0.52 1.23 80 5676 0 1419
Misses in library cache during parse: 0
Optimizer mode: FIRST_ROWS
Parsing user id: 987 (recursive depth: 1)
Rows Row Source Operation
------- ---------------------------------------------------
99 TABLE ACCESS BY INDEX ROWID IDNT (cr=396 pr=63 pw=0 time=457354 us)
99 INDEX UNIQUE SCAN IDNTP1 (cr=297 pr=29 pw=0 time=200551
us)(object id 285949)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait TotalWaited
thanks for any suggestions,
Peter Sylvester
MITRE Corp.
-- http://www.freelists.org/webpage/oracle-lReceived on Wed Jun 13 2007 - 18:38:19 CDT
 |
 |