Re: TKPROF output

From: <lyallbarbour_at_sanfranmail.com>
Date: Tue, 05 Apr 2011 08:41:05 -0400
Message-Id: <8CDC1A5DD00D2CA-784-3237_at_web-mmc-d01.sysops.aol.com>

It was traced on a separate "training" system with noone else on. On the session that was logged into Forms, i ran the Trace through EM with that specific session. When the execute finished i stopped the Trace. What's interesting, and why i haven't responded to some of the responses to this, is that the vendor finished a new Release of this Application and a specific "fix" for the performance of this screen. When i Trace this session in this latest Release, there's much less SQL's being run and no specific SQL that has any waits of any kind... So their redesign has sped up the processing of this screen, unfortunately, i do not know why that other issue was happening before. Thanks for all the responses and i definitely understand those kinds of Waits better now. Technically, i do not need to solve this problem anymore since the Vendor's Release re-engineered the processing so the problem doesn't exist anymore. Lyall      

-----Original Message-----

From: D'Hooge Freek <Freek.DHooge_at_uptime.be> To: lyallbarbour_at_sanfranmail.com <lyallbarbour_at_sanfranmail.com>; oracle-l_at_freelists.org <oracle-l_at_freelists.org> Sent: Thu, Mar 31, 2011 2:01 am
Subject: RE: TKPROF output

Hi,

The main wait time is "sql*net message from client", meaning that you are

waiting on response from the aplication server.

Can you check in the raw trace file if these waits are happening between the

fetches or not?

If they are happening between the fetches, it means that the application server

is slow to request more rows from the query result.

Reason for this could be some processing that happens on the application server

or maybe a network problem (like a wrong dns server on the application server).

If the waits are happening after all the fetches are completed, then these waits

are probably not relevant (unless you are sure that the trace was stopped at the

moment the application showed the result of the query).

How did you trace this session?

regards,

Freek D'Hooge

Uptime

Oracle Database Administrator

email: freek.dhooge_at_uptime.be

tel +32(0)3 451 23 82

http://www.uptime.be

disclaimer: www.uptime.be/disclaimer

---

From: oracle-l-bounce_at_freelists.org [oracle-l-bounce_at_freelists.org] On Behalf Of

lyallbarbour_at_sanfranmail.com [lyallbarbour_at_sanfranmail.com]

Sent: 30 March 2011 20:55

To: oracle-l_at_freelists.org

Subject: TKPROF output

Trying to understand Fetch in a TKPROF output. We have an application on Oracle

Apps Server 10.1 Database 10.2.0.4 On production, a specific query runs in

about 3 seconds. On this new database server we created, it runs about 30 secs.

Looks like the query does the same thing in the database, but we have a ton of

SQL*Net message waits on the query below. What are Fetches? What are reasons

why waits for SQL*Net messaging happens that relate to Fetches? See below...

Here it is:

SELECT ROWID,SCRAP_ID,TX_ID,SHIFT_ID,ON_TX_ID,SCRAP_COMP_CODE,WEIGHT_UOM,   DEPT_CODE,INV_COMP_CODE,INV_ITEM_CODE,SCRAP_CODE,TYPE,CUST_NUM,PART,   QUANTITY,LENGTH,SCRAP_WEIGHT,TX_START_DT,RESPONSIBILITY_CODE,DEFECT_CODE,   NOTES FROM  ST_PRODTX_SCRAP WHERE (WEIGHT_UOM=:1) call count cpu elapsed disk query current rows

• ------ -------- ---------- ---------- ---------- ---------- ----------

Parse 1 0.00 0.00 0 0 0 0

Execute 1 0.00 0.00 0 0 0 0

Fetch 27457 0.91 0.90 0 29757 0 164741

• ------ -------- ---------- ---------- ---------- ---------- ----------

total 27459 0.91 0.90 0 29757 0 164741

Misses in library cache during parse: 1

Misses in library cache during execute: 1

Optimizer mode: ALL_ROWS

Parsing user id: 677 (LBARBOUR)

Rows Row Source Operation

• ---------------------------------------------------

 164741 TABLE ACCESS FULL ST_PRODTX_SCRAP (cr=29757 pr=0 pw=0 time=165118 us)

Rows Execution Plan

• ---------------------------------------------------

      0 SELECT STATEMENT MODE: ALL_ROWS  164741 TABLE ACCESS MODE: ANALYZED (FULL) OF 'ST_PRODTX_SCRAP' (TABLE) Elapsed times include waiting on following events:

  Event waited on                             Times   Max. Wait  Total Waited

  ----------------------------------------   Waited  ----------  ------------

  SQL*Net message to client                   27457        0.00          0.01

  SQL*Net message from client                 27457        1.07        100.33--

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

=

--

http://www.freelists.org/webpage/oracle-l Received on Tue Apr 05 2011 - 07:41:05 CDT