dbTalk Databases Forums  

why would 1 query take 20X more SQL*Net message from client[idel] time than almost identical quieres

comp.database.oracle.server comp.database.oracle.server


Discuss why would 1 query take 20X more SQL*Net message from client[idel] time than almost identical quieres in the comp.database.oracle.server forum.



Reply
 
Thread Tools Display Modes
  #1  
Old   
mistton
 
Posts: n/a

Default why would 1 query take 20X more SQL*Net message from client[idel] time than almost identical quieres - 03-01-2007 , 06:03 AM






Running Oracle Version: 9.2.0.3.0 on Solaris 8 and Sun E15 10 CPU server.

Have client app from vendor (JAVA applet on IE 6) that runs an Oracle
process at user request. The process is taking 20 minutes to run which is
totally unacceptable

Client is just sending commands to do stuff on database it does virtually
no more work than that. (on client box its at 0% almost 99% of the time).
once Oracle is finished it displays results by reading final results table.

looked at what oracle is doing and found that CPU, I/O, reads etc taking up
only 2 minutes rest is almost all idle time.

PROBLEM:
One statement (almost identical to many others) is taking up 50% of SQL NET
idle time, and it spends 95% of its total time in it. The statement is
reading 1 row from a 1 row table holding currency info for USA, all
varchar2 or date


Did extended event tracing.

here is Session Flat Profile :
Found Total SQL Statements: 730 (699 user statements, 31 internal
statements)

Note that SQL*Net message from client [idle] = 71.1%

Event % Time Seconds Calls -
Time per Call - Avg Min Max
SQL*Net message from client [idle] 71.1% 845.1453s 193,429 0.0043s
0.0002s 144.0487s
unaccounted-for time 11.3% 134.5177s
SQL*Net message from client 8.8% 104.7639s 87,046 0.0012s 0.0002s
5.1978s
EXEC calls [CPU] 4.2% 49.4900s 88,576 0.0005s -0.0300s 2.8500s
FETCH calls [CPU] 2.7% 32.5700s 88,020 0.0003s 0.0000s 1.5000s
PARSE calls [CPU] 1.1% 12.9100s 82,072 0.0001s -0.0100s 0.1300s
db file sequential read 0.6% 7.6449s 2,452 0.0031s 0.0000s 0.1114s
SQL*Net message to client 0.0% 0.7370s 280,476 0.0000s 0.0000s
0.0161s
SQL*Net more data to client 0.0% 0.2933s 3,899 0.0000s 0.0000s
0.0004s
db file scattered read 0.0% 0.2846s 88 0.0032s 0.0004s 0.0384s
log file switch completion 0.0% 0.1399s 9 0.0155s 0.0000s 0.0407s
SQL*Net more data from client 0.0% 0.0768s 880 0.0000s 0.0000s
0.0007s
log file sync 0.0% 0.0006s 1 0.0006s 0.0006s 0.0006s
Total 100.0% 1,188.5742s


Ok, SQL*NET is taking alot of time. well looking deeper i found that one
statement is taking up 50% of it and it spends 95% of its time in it. the
statement is reading 1 row from a 1 row table hold currency info for USA.

Top 5 Statements per Event
SQL*Net message from client [idle]
SQL Statement Id % Time Seconds Calls - Time per Call -
Avg Min Max
978251952 48.8% 412.2861s 26,840 0.0153s 0.0002s 0.4931s
Cursor #0 23.9% 201.8160s 91 2.2178s 0.0003s 144.0487s
3672891858 3.5% 29.1940s 26,850 0.0010s 0.0002s 0.3531s


Statement Flat Profile for 978251952
FETCH calls [CPU] 0.5% 2.0200s 8,950 0.0002s 0.0
Avg Min Max
SQL*Net message from client [idle] 95.6% 412.2861s 26,840 0.0153s
0.0002s 0.4931s
SQL*Net message from client 3.2% 13.6379s 8,950 0.0015s 0.0003s
0.2314s
FETCH calls [CPU] 0.5% 2.0200s 8,950 0.0002s 0.0000s 0.0100s
PARSE calls [CPU] 0.4% 1.6800s 8,950 0.0001s 0.0000s 0.0100s
EXEC calls [CPU] 0.3% 1.4300s 8,950 0.0001s 0.0000s 0.0100s
SQL*Net message to client 0.0% 0.1358s 44,730 0.0000s 0.0000s 0.0064s
db file sequential read 0.0% 0.0169s 1 0.0169s 0.0169s 0.0169s
Total 100.0% 431.2067s


i found almost identical statements that are consumming much less of SQL
Net time. they were done same amount of times etc

for example
bad one

select currencyid, currencycode, caption, ratecaption, scalefactor,
decimalplaces, lastuser, lastedited
from currency_country
order by currencycode

Statement Cumulative Statistics
Call Cache
Misses Count - Seconds - Physical
Reads - Logical Reads - Rows
CPU Elapsed Consistent Current
Parse 1 8,950 1.6800s 2.0592s 0 0 0 0
Exec 0 8,950 1.4300s 1.7247s 0 0 0 0
Fetch 8,950 2.0200s 2.3454s 1 17,900 0 8,950
Total 1 26,850 5.1300s 6.1293s 1 17,900 0 8,950


good one
select departmentid from bucket where bucketid = :v0

Statement Cumulative Statistics
Call Cache
Misses Count - Seconds - Physical
Reads - Logical Reads - Rows
CPU Elapsed Consistent Current
Parse 1 12,059 0.7000s 1.3558s 0 0 0 0
Exec 0 12,059 0.6200s 2.9514s 0 0 0 0
Fetch 12,059 2.0700s 1.6046s 0 36,177 0 12,059
Total 1 36,177 3.3900s 5.9118s 0 36,177 0 12,059


what is happening? is it totally how the client is working is ther nothing
at the Oracle end?

Reply With Quote
Reply




Thread Tools
Display Modes

Posting Rules
You may not post new threads
You may not post replies
You may not post attachments
You may not edit your posts

vB code is On
Smilies are On
[IMG] code is On
HTML code is Off



Powered by vBulletin Version 3.5.3
Copyright ©2000 - 2012, Jelsoft Enterprises Ltd.