On Mar 1, 9:35 am, mistton <s..._at_dsfds.com> wrote:
> 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.
>
> is it possible that say client does 10 queires problem one being last one
> then does work than talks to Oracle again and the idle time is added to
> this query?
>
> 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?
What exactly makes you think the time is spent executing database
code? Have you ruled out the client side completely? (at a glance, the
stats above seem to suggest that very little of the 20 minutes is
spent inside database)
Received on Thu Mar 01 2007 - 13:11:27 CST
