RE: Manual execution vs v$session discrepancy

From: Jonathan Lewis <jonathan_at_jlcomp.demon.co.uk>
Date: Thu, 3 Sep 2015 06:51:31 +0000
Message-ID: <CE70217733273F49A8A162EE074F64D9282A2451_at_EXMBX01.thus.corp>


It's perfectly feasible for a session to report a much longer run-time for a query than v$sql shows. The session time you're looking at may include all the network roundtrip time and any client processing time that goes on between round-trips.

As far as dealing with 7 seconds vs. 2/10th seconds - some of that may be down to the way the client and server communicate, some of it may be down to the server being busy while the production query was being run, some may be down very specifically to the concurrency of usage (competing for latches and mutexes, driving up CPU time), some may be down to the production data being subject to update and read-consistency overheads while the queries were being run. However, the difference does look a little extreme so ...

Apart from acquiring sets of bind values, did you also acquire the bind values used when the cursors were optimised ? Did you check the plan(s) actually used matched the plan(s) your tests produced.

When you tested did you use the bind variable sets as literals to the query, or did you have a framework that injected them as bind variables of the correct type? When you tested was it against the same data set with the same set of object statistics and similar concurrent rate of change of data ? When you queried v$sql how many child cursors were in existence (and what was the highest child number) ? If there were multiple child cursors was there much variation in the stats between children. Were the figures in v$sqlstat consistent with those in v$sql. vary Did the details from v$sql show you similar buffer_gets in the production and test cases. There are several time-related columns in v$sql beyond elapsed_time and cpu_time (e.g. plsql_exec_time, java_exec_time, user_io_wait_time, cluster_wait_time) are there any clues where the time was spent?

Regards
Jonathan Lewis
http://jonathanlewis.wordpress.com
_at_jloracle



From: oracle-l-bounce_at_freelists.org [oracle-l-bounce_at_freelists.org] on behalf of Ram Raman [veeeraman_at_gmail.com] Sent: 03 September 2015 03:50
To: ORACLE-L
Subject: Manual execution vs v$session discrepancy

List,

We had a SQL that was being run repeatedly over 10K times in our prod system today. Turned out to be something related to fiscal year. It spiked up our CPU big time. I got several value sets for the SQL from the sql bind capture and executed them myself for about a dozen value sets; each and everyone of my manual execution returned in about 2/10ths of a second. However the v$session view would show the sessions run that SQL (sql_id, last_call_et, status) for a few minutes. That was the case for several users the whole day. Per v$sql, the average execution time for that SQL was 7 seconds since the first load this morning. AWR reports showed that the averages are anywhere from 4 seconds and up depending on the hour. I was confused by what the v$session showed me vs my execution times. Am I missing something here? bind capture interval is left at default 900 seconds.

Could it be that the values I checked (about 15) just happened to be 'good values' or the environment could have been different for the executed SQLs? I was hesitant to turn on the trace with the CPU usage through the roof. v10.2

Thanks.

--

--

http://www.freelists.org/webpage/oracle-l Received on Thu Sep 03 2015 - 08:51:31 CEST

Original text of this message