Re: Tracing
Date: Thu, 19 Nov 2009 12:37:23 -0800 (PST)
Message-ID: <d63eca94-530f-4357-a5bc-0e29c65cf4ca_at_v30g2000yqm.googlegroups.com>
On Nov 19, 11:45 am, The Magnet <a..._at_unsu.com> wrote:
> Hi,
>
> When tracing SQL statements from SQLPLUS to see consistent gets and
> such, if the query contains bind variables or constants, how do you
> 'emulate' that in SQLPLUS and perform the trace? Here is an example:
>
> This is in one of our stored procedures. It does 5500 consistent
> gets. I want to try and bring that down, but, I'm thinking I can't
> because of the literals. If I change those to bind variables as well
> as the 237 constant, how can I trace that from SQLPLUS?
>
> SELECT subgroup_id, max_allowed_subscr, allow_new_subscriptions,
> priority
> FROM (SELECT ts.subgroup_id, max_allowed_subscr,
> allow_new_subscriptions, priority, COUNT(ts.subgroup_id)
> OVER (PARTITION BY ts.subgroup_id, ts.newsletter_id)
> number_in_group, ROW_NUMBER()
> OVER (PARTITION BY ts.subgroup_id, ts.newsletter_id ORDER BY
> priority) rnum
> FROM engine.ts_subgroups ts, engine.ts_customers tc,
> engine.customer_order co,
> engine.order_line ol, engine.product p
> WHERE ts.subgroup_id = tc.subgroup_id
> AND tc.customer_id = co.customer_id
> AND co.order_id = ol.order_id
> AND ol.product_id = p.product_id
> AND ol.status IN ('Active','Pending')
> AND p.subproduct_id = 237
> AND ts.newsletter_id = 237)
> WHERE rnum = 1;
Here is the general procedure with a different SQL statement (you MUST
disable autotrace, the first line will have an impact later - ignore
for now):
SQL> ALTER SESSION SET STATISTICS_LEVEL='ALL';
SQL> VARIABLE N1 NUMBER SQL> VARIABLE N2 NUMBER SQL> EXEC :N1:=1 SQL> EXEC :N2:=100
SQL> SELECT
2 T3.C1,
3 T4.C2
4 FROM
5 T3,
6 T4
7 WHERE
8 T3.C1 BETWEEN :N1 AND :N2
9 AND T3.C1=T4.C1;
SQL> SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR
(NULL,NULL,'TYPICAL'));
SQL_ID 41rcjcqgz38z2, child number 0
SELECT T3.C1, T4.C2 FROM T3, T4 WHERE T3.C1 BETWEEN :N1
AND :N2 AND T3.C1=T4.C1 Plan hash value: 1980773432
|Id |Operation |Name | Rows | Bytes | Cost (%CPU)| Time | ------------------------------------------------------------------------------------ | 0|SELECT STATEMENT | | | | 52 (100)| | |* 1| FILTER | | | | | | |* 2| HASH JOIN | | 99 | 10692 | 52 (2)| 00:00:01 | |* 3| TABLE ACCESS FULL |T3 | 100 | 400 | 47 (0)| 00:00:01 | | 4| TABLE ACCESS BY INDEX ROWID|T4 | 100 | 10400 | 4 (0)| 00:00:01 | |* 5| INDEX RANGE SCAN |IND_T4 | 100 | | 2(0)| 00:00:01 |
Predicate Information (identified by operation id):
1 - filter(:N1<=:N2)
2 - access("T3"."C1"="T4"."C1")
3 - filter(("T3"."C1"<=:N2 AND "T3"."C1">=:N1))
5 - access("T4"."C1">=:N1 AND "T4"."C1"<=:N2)
Autotrace and EXPLAIN PLAN will sometimes lie about the actual execution plan, especially when the execution plan contains bind variables. You could take the above a step further like this to see the actual number of rows returned (the above *is* the actual plan):
SQL> VARIABLE N1 NUMBER SQL> VARIABLE N2 NUMBER SQL> EXEC :N1:=1 SQL> EXEC :N2:=100
SQL> EXEC :N2:=10000
SQL> SELECT
2 T3.C1,
3 T4.C2
4 FROM
5 T3,
6 T4
7 WHERE
8 T3.C1 BETWEEN :N1 AND :N2
9 AND T3.C1=T4.C1;
SQL> SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'ALLSTATS
LAST'));
Plan hash value: 1980773432
| Id | Operation | Name | Starts | E-Rows | A-Rows |
| 0 | SELECT STATEMENT | | 1 | | 10000 | |* 1 | FILTER | | 1 | | 10000 | |* 2 | HASH JOIN | | 1 | 99 | 10000 | |* 3 | TABLE ACCESS FULL | T3 | 1 | 100 | 10000 | | 4 | TABLE ACCESS BY INDEX ROWID| T4 | 1 | 100 | 10000 | |* 5 | INDEX RANGE SCAN | IND_T4 | 1 | 100 | 10000 | --------------------------------------------------------------------------- ------------------------------------------------------------| A-Time | Buffers | Reads | OMem | 1Mem | Used-Mem |
|00:00:00.07 | 1666 | 355 | | | | |00:00:00.07 | 1666 | 355 | | | | |00:00:00.07 | 1666 | 355 | 1517K| 1517K| 1882K (0)| |00:00:00.07 | 158 | 155 | | | | |00:00:00.01 | 1508 | 200 | | | | |00:00:00.01 | 687 | 32 | | | | ------------------------------------------------------------
Predicate Information (identified by operation id):
1 - filter(:N1<=:N2)
2 - access("T3"."C1"="T4"."C1")
3 - filter(("T3"."C1"<=:N2 AND "T3"."C1">=:N1))
5 - access("T4"."C1">=:N1 AND "T4"."C1"<=:N2)
In the above, notice that the E-Rows column still shows that Oracle is estimating that 100 rows will be returned by many steps in the plan, while the A-Rows column shows that 10,000 rows were actually returned. The Buffers column shows the number of consistent gets and the Reads column shows the number of blocks read from disk. Note that with ALTER SESSION SET STATISTICS_LEVEL='ALL' the query could require much longer to execute, especially prior to Oracle 11.1.0.6. You could add a /*+ GATHER_PLAN_STATISTICS */ hint to the SQL statement rather than changing the STATISTICS_LEVEL parameter.
Charles Hooper
IT Manager/Oracle DBA
K&M Machine-Fabricating, Inc.
Received on Thu Nov 19 2009 - 14:37:23 CST