You Asked
I'm relatively familiar with using SQL_TRACE and tkprof for tuning, but I recently spotted something in a tkprof report for one of our customers that raised my suspicions.
There is a lot of SQL in the file where the number of library cache execution misses seems high - almost as high as the number of executions for a lot of statements executed a few times (say a half-dozen), and for statements run a few dozen or a couple of hundred times, there are usually at least two or three of the 'misses during execute'.
Here's an interesting one:
SELECT v3.GTTE_UNIQUENAME uniquename,
v1.TAILORCODE,
v1.TEMPLATEVERSIONID,
v1.TEMPLATEID,
v1.GTTV_VERSION,
v1.GTTV_APPROVED,
v1.GTTV_DISPLAYNAME,
v1.GTTV_PRIORITY,
v1.GTTV_TARGETDAYS,
v1.GTTV_DESCRIPTION,
v1.GTTV_NONCASEDIALOGUE,
v1.GTTV_CASEPRECONMAPPINGGROUPID,
v2.RANKING,
v2.BusinessGroupRequired
FROM gt_templateversion v1,
gt_template v3, (SELECT v.tailorcode, v.templateversionid, v.ranking, v.BusinessGroupRequired, rank() over(PARTITION BY v.uniquename ORDER BY ranking ASC, decode(v.tailorcode, :1 , 1, 0) DESC ) AS r_num FROM gt_latestversion_v v WHERE v.tailorcode IN ('BASE', 'TEST', :2 ) ) v2 WHERE v1.tailorcode = v2.tailorcode AND v1.templateversionid = v2.templateversionid AND v3.templateid = v1.TEMPLATEID
AND v3.tailorcode = v1.TAILORCODE AND v2.r_num = 1 AND (1 != :3 OR nvl(v1.gttv_noncasedialogue, 0) != 1) AND EXISTS ( SELECT 1 FROM gt_task_o t WHERE t.tailorcode = v1.tailorcode AND t.templateversionid = v1.templateversionid AND t.gtta_tasktype = 'START' AND NOT EXISTS (SELECT 1 FROM gt_propertyvalue_o p WHERE p.tailorcode = t.tailorcode AND p.taskid = t.taskid AND p.gtpv_propertyname = 'requiredEntity')) ORDER BY v3.GTTE_UNIQUENAME ASC
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 4 0.00 0.00 0 0 0 0
Execute 4 1.78 2.89 0 0 0 0
Fetch 220 1.11 2.28 329 250604 0 2184
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 228 2.90 5.18 329 250604 0 2184
Misses in library cache during parse: 4
Misses in library cache during execute: 4
Optimizer mode: ALL_ROWS
Parsing user id: 5064
Number of plan statistics captured: 4
Not only is 'misses during execute' = executions, but also parses = executions = misses during parse as well
Library cache miss during parse is something we're all familiar with - new SQL (or SQL that was aged out since last run).
Parses = executions is normal for this code, which is JDBC code and so tends to submit SQL text every time and incur a lot of soft parses, rather than say a C application that would cache cursors and rebind. But at least they're soft parses.
Miss during execution is a new[ly reported] phenomenon: I belive it means 'SQL text found but cursor not valid for reuse'. Either object invalidation through DDL or different objects referenced/privileges meaning a new child cursor must be spawned.
What's particularly baffling in this case is that every time the SQL was submitted it incurred a hard parse (bad enough), but then a further miss when it came to be executed. That baffles me - normally (and certainly for code submitted via JDBC) one parses and then immediately executes as a single step. I don't see how it could have lost or invalidated the plan between the two steps.
Any ideas on what to look for? I presume V$SQL_SHARED_CURSOR might show some light, but as it's a customer site I'd rather have a series of diagnostics to run in one go rather than send them things to look at piecemeal.
Can the shared pool really be so stressed on this system? Our app is reasonably well-behaved with using binds on queries, but it does throw out a lot of anonymous PL/SQL blocks with literals. This is something I recently discovered and am agitating to correct, but it hasn't been crippling in effect on any other installation I've seen. The number of hard parses/s in the Statspack/AWR reports is not zero, but not massively worse than any other site I've seen.
Is bind-sensitive SQL a possible explanation of some of these observations - if a reparse occurs because the optimizer thinks an execution with a new bind value needs a new plan, does that show up as a 'miss in library cache during execute'?
I'm also puzzled at the high cpu/elapsed during the EXECUTE phase, given it's a SELECT. I thought maybe this was where the parse time incurred due to a library cache miss during execute might show up. However, it also shows 4 parses and 4 'library cache misses during parse' but no time spent parsing. This statement quite complicated and against a couple of nasty views, so I would expect measurable parse time for it, going on similar queries in our system.
and Connor said...
The trace file should have the sqlid.
So query v$sql_shared_cursor for that sqlid. You should see the children and why they could not be shared.
Hope this helps.
Rating
(1 rating)
Is this answer out of date? If it is, please let us know via a Comment