Oracle-L: RE: 10046 Trace file waits

From: Cary Millsap <cary.millsap_at_hotsos.com>
Date: Tue, 18 Mar 2003 08:39:06 -0800
Message-ID: <F001.0056C978.20030318083906@fatcity.com>

This is trace data from 9.2.0.2+ (you can tell because of the new STAT data). Therefore the timings are expressed in microseconds (0.000001-second units).

Technically, to answer your question, you have to know whether or not the application invokes the fetch immediately after the execute. It probably does, because the duration of the socket read ("message from client") is only 23743 microseconds, which is only 0.023743 seconds. The duration of this syscall is not a problem.

Cary Millsap
Hotsos Enterprises, Ltd.
http://www.hotsos.com

Upcoming events:
- Hotsos Clinic 101, Mar 25-27 Oxford
- Hotsos Clinic 101, Apr 8-10 Chicago

-----Original Message-----
- IL
Sent: Tuesday, March 18, 2003 8:09 AM
To: Multiple recipients of list ORACLE-L

We are having some performance problems at a client. I ran a 10046 trace, level 8 on the DB for about 5 minutes of test operations. From the trace files generated I find someting of the following:

SELECT Tm_trade_in_error.trade_id, Tm_trade_in_error.account_number, Tm_trade_in_error.aps_groupid, Tm_trade_in
_error.broker_receipt_source_code,

Tm_trade_in_error.broker_receipt_timestamp,
Tm_trade_in_error.business_cycle_
code, Tm_trade_in_error.buy_sell_ind, Tm_trade_in_error.cabinet_ind,
Tm_trade_in_error.card_code, Tm_trade_in_er
ror.card_order, Tm_trade_in_error.clearing_cycle_id,
Tm_trade_in_error.clearing_date, Tm_trade_in_error.commodit

y_code, Tm_trade_in_error.contract_day, Tm_trade_in_error.contract_month, Tm_trade_in_error.contract_type, Tm_tr

ade_in_error.contract_year, Tm_trade_in_error.contra_match_code,
Tm_trade_in_error.cti_code, Tm_trade_in_error.c
tr_card_seq, Tm_trade_in_error.entry_clearing_date,

Tm_trade_in_error.entry_source_code, Tm_trade_in_error.entry
_time, Tm_trade_in_error.error_codes, Tm_trade_in_error.exch_code,

Tm_trade_in_error.execution_timestamp, Tm_tra
de_in_error.execution_timestamp_source_cod,
Tm_trade_in_error.exec_broker_code, Tm_trade_in_error.exercise_price

, Tm_trade_in_error.exercise_style, Tm_trade_in_error.external_tradeid, Tm_trade_in_error.fee_code, Tm_trade_in_ error.firm_entered_memo, Tm_trade_in_error.firm_id,

Tm_trade_in_error.floor_broker_code, Tm_trade_in_error.legac
y_id, Tm_trade_in_error.make_up_code, Tm_trade_in_error.matched_ind,
Tm_trade_in_error.match_block_seq, Tm_trade

_in_error.mod_date, Tm_trade_in_error.mod_program,
Tm_trade_in_error.mod_user, Tm_trade_in_error.open_close_ind, Tm_trade_in_error.opposing_broker_code, Tm_trade_in_error.opposing_firm_id, Tm_trade_in_error.order_execution_t
ime, Tm_trade_in_error.order_type, Tm_trade_in_error.origin_code,

Tm_trade_in_error.prematched_seq_no, Tm_trade_
in_error.put_call_ind, Tm_trade_in_error.session_id,
Tm_trade_in_error.spread_differential, Tm_trade_in_error.sp

read_sign, Tm_trade_in_error.spread_type, Tm_trade_in_error.timestamp_in,

Tm_trade_in_error.timestamp_in_source_
code, Tm_trade_in_error.timestamp_out,
Tm_trade_in_error.timestamp_out_source_code, Tm_trade_in_error.time_brack

et_code, Tm_trade_in_error.trade_day, Tm_trade_in_error.trade_gu_ind, Tm_trade_in_error.trade_month, Tm_trade_in
_error.trade_price, Tm_trade_in_error.trade_qty,
Tm_trade_in_error.trade_route_ind, Tm_trade_in_error.trade_sour ce, Tm_trade_in_error.trade_status, Tm_trade_in_error.trade_year,

Tm_trade_in_error.transfer_reason_code, Tm_tra
de_in_error.trans_type, Tm_trade_in_error.underlying_exercise_price,
Tm_trade_in_error.underlying_exercise_price

_sign, Tm_trade_in_error.underlying_expiration_day,
Tm_trade_in_error.underlying_expiration_month, Tm_trade_in_e rror.underlying_expiration_year, Tm_trade_in_error.underlying_product_type, Tm_trade_in_error.underlying_put_cal
l FROM TM_TRADE_IN_ERROR WHERE MATCH_BLOCK_SEQ = :1 END OF STMT
PARSE #4:c=0,e=148,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=108983137752

EXEC #4:c=0,e=95,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=108983138287
WAIT #4: nam='SQL*Net message to client' ela= 2 p1=1413697536 p2=1 p3=0
WAIT #4: nam='SQL*Net more data to client' ela= 78 p1=1413697536 p2=2001

p3=0
WAIT #4: nam='SQL*Net more data to client' ela= 41 p1=1413697536 p2=2002 p3=0
WAIT #4: nam='SQL*Net message from client' ela= 23743 p1=1413697536 p2=1 p3=0
FETCH #4:c=0,e=78,p=0,cr=1,cu=0,mis=0,r=0,dep=0,og=4,tim=108983162738 WAIT #4: nam='SQL*Net message to client' ela= 2 p1=1413697536 p2=1 p3=0 WAIT #4: nam='SQL*Net message from client' ela= 22030 p1=1413697536 p2=1 p3=0

STAT #14 id=1 cnt=1 pid=0 pos=1 obj=6471 op='TABLE ACCESS BY INDEX ROWID
REF_SESSION (cr=2 r=0 w=0 time=59 us)'
STAT #14 id=2 cnt=1 pid=1 pos=1 obj=6472 op='INDEX UNIQUE SCAN

XPKREF_SESSION (cr=1 r=0 w=0 time=27 us)'

Now, what catchs my eye is the first SQL*Net message from client wait, before fetch#4. Is this a real wait, or is this truly just an idle wait. I find it odd that it happens *before* the fetch, but maybe I'm reading this wrong. Can someone enlighten me please?

-- 
Please see the official ORACLE-L FAQ: http://www.orafaq.net
-- 
Author: Freeman Robert - IL
  INET: FREEMANR_at_tusc.com

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: ListGuru_at_fatcity.com (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: cary.millsap_at_hotsos.com

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: ListGuru_at_fatcity.com (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).

Received on Tue Mar 18 2003 - 10:39:06 CST