December 8, 2009 (note added December 9, 2009)
An interesting post from almost two years ago in the comp.databases.oracle.server Usenet group:
http://groups.google.com/group/comp.databases.oracle.server/browse_thread/thread/e0599d3e043fc199
select distinct name from all_source; ....... SYS_YOID0000052452$ ...... 3196 rows selected.Ok no problem.
select distinct owner from v$access SQL> / select distinct owner from v$access * ERROR at line 1: ORA-01013: user requested cancel of current operationI had to terminate it as it become non-terminating.
“select owner from v$access” returns a mere 193 rows, and it cannot sort it?
I suspect there is exists an infinite loop somewhere.
This was attempted on 10gR2, 11gR1 and both had the same problem.
How would someone start investigating this problem? Find something that appears out of the ordinary, and start probing. This is the approach that I used:
–
I was able to reproduce this problem on Oracle 10.2.0.2 with the Oracle October 2006 CPU on 64 bit Windows 2003.
From the udump trace file:
ksedmp: internal or fatal error ORA-07445: exception encountered: core dump [ACCESS_VIOLATION] [__intel_new_memcpy+610] [PC:0x3236532] [ADDR:0x0] [UNABLE_TO_READ] [] Current SQL statement for this session: select distinct owner from v$access ----- Call Stack Trace ----- calling call entry argument values in hex location type point (? means dubious value) -------------------- -------- -------------------- ---------------------------- __intel_new_memcpy+ 0000000000000000 000000000 000000000 0118AF5A0 610 7FF970C7598 000007FF95D155F0 CALL??? __intel_new_memcpy+ 0000007FF 013DF42E8 001749686 610 000000000 ...
From a 10046 trace at level 8:
*** 2008-01-23 06:51:57.901 WAIT #3: nam='latch: library cache' ela= 8566 address=1398554576 number=214 tries=1 obj#=-1 tim=5204643696 WAIT #3: nam='latch: library cache' ela= 859 address=1398554576 number=214 tries=1 obj#=-1 tim=5205047765 WAIT #3: nam='latch: library cache' ela= 2958 address=1398554576 number=214 tries=1 obj#=-1 tim=5205183748 WAIT #3: nam='latch: library cache' ela= 551 address=1398554576 number=214 tries=1 obj#=-1 tim=5205267198 *** 2008-01-23 06:54:39.117 WAIT #3: nam='latch: library cache' ela= 813 address=1398554576 number=214 tries=1 obj#=-1 tim=5365848854 *** 2008-01-23 06:55:06.288 WAIT #3: nam='latch: library cache' ela= 30 address=1398554576 number=214 tries=1 obj#=-1 tim=5393019180 *** 2008-01-23 06:55:30.006 WAIT #3: nam='latch: library cache' ela= 68 address=1398554576 number=214 tries=1 obj#=-1 tim=5416746379 *** 2008-01-23 06:55:50.584 WAIT #3: nam='latch: library cache' ela= 33 address=1398554576 number=214 tries=1 obj#=-1 tim=5437323921 *** 2008-01-23 06:57:09.536 WAIT #3: nam='latch: library cache' ela= 111 address=1398554576 number=214 tries=1 obj#=-1 tim=5516279642 *** 2008-01-23 06:57:20.895 WAIT #3: nam='latch: library cache' ela= 77 address=1398554576 number=214 tries=1 obj#=-1 tim=5527627340 *** 2008-01-23 06:57:36.082 WAIT #3: nam='latch: library cache' ela= 246 address=1398554576 number=214 tries=1 obj#=-1 tim=5542815685 *** 2008-01-23 06:57:57.957 WAIT #3: nam='latch: library cache' ela= 123 address=1398554576 number=214 tries=1 obj#=-1 tim=5564704225 *** 2008-01-23 06:58:14.644 WAIT #3: nam='latch: library cache' ela= 63 address=1398554576 number=214 tries=1 obj#=-1 tim=5581385020 *** 2008-01-23 06:58:26.269 WAIT #3: nam='latch: library cache' ela= 62 address=1398554576 number=214 tries=1 obj#=-1 tim=5593004724 *** 2008-01-23 06:58:48.346 WAIT #3: nam='latch: library cache' ela= 42 address=1398554576 number=214 tries=1 obj#=-1 tim=5615094241 WAIT #3: nam='latch: library cache' ela= 8 address=1398554576 number=214 tries=1 obj#=-1 tim=5615168161 ...
For an average 60 second interval interval, the session had the following latch statistics:
Latch Child# Level Gets Misses Sleeps Sleeps1 LIBRARY CACHE 1 5 529418 25 0 25 LIBRARY CACHE 2 5 539720 36 0 36 LIBRARY CACHE 3 5 519189 15 0 15 LIBRARY CACHE 4 5 516501 55 0 55 LIBRARY CACHE 5 5 524907 1744 4 1740
On the waits, P1 is 13985, P2 is 214, P3 is 0, Buf is 99, SQL Hash is 3250939240.
SELECT SQL_TEXT FROM V$SQL WHERE HASH_VALUE=3250939240 SQL_TEXT ----------------------------------- select distinct owner from v$access
SELECT ID, SUBSTR(OPERATION,1,12) OPERATION, SUBSTR(OPTIONS,1,12) OPTIONS, SUBSTR(OBJECT_OWNER||'.'||OBJECT_NAME,1,20) OBJECT, SUBSTR(OBJECT_TYPE,1,13) OBJECT_TYPE, PARENT_ID, DEPTH, POSITION, CPU_COST FROM V$SQL_PLAN_STATISTICS_ALL WHERE HASH_VALUE=3250939240 AND CHILD_NUMBER=1 ORDER BY ID; ID OPERATION OPTIONS OBJECT OBJECT_TYPE PARENT_ID DEPTH POSITION CPU_COST -- ------------ ------------ -------------------- ------------- ---------- ---------- ---------- ---------- 1 HASH UNIQUE . 0 1 1 2142850 2 NESTED LOOPS . 1 2 1 1115000 3 NESTED LOOPS . 2 3 1 1080000 4 MERGE JOIN CARTESIAN . 3 4 1 730000 5 FIXED TABLE FULL SYS.X$KSUSE TABLE (FIXED) 4 5 1 380000 6 BUFFER SORT . 4 5 2 350000 7 FIXED TABLE FULL SYS.X$KGLDP TABLE (FIXED) 6 6 1 350000 8 FIXED TABLE FIXED INDEX SYS.X$KGLLK (ind:1) TABLE (FIXED) 3 4 2 3500 9 FIXED TABLE FIXED INDEX SYS.X$KGLOB (ind:1) TABLE (FIXED) 2 3 2 3500
SELECT
ID,
ACCESS_PREDICATES,
FILTER_PREDICATES
FROM
V$SQL_PLAN_STATISTICS_ALL
WHERE
HASH_VALUE=3250939240
AND CHILD_NUMBER=1
ORDER BY
ID;
ID ACCESS_PREDICATES FILTER_PREDICATES
-- ----------------- -----------------
1
2
3
4
5 "S"."INST_ID"=USERENV('INSTANCE')
6
7
8 ("L"."KGLLKUSE"="S"."ADDR" AND "L"."KGLLKHDL"="D"."KGLHDADR" AND "L"."KGLNAHSH"="D"."KGLNAHSH")
9 ("O"."KGLNAHSH"="D"."KGLRFHSH" AND "O"."KGLHDADR"="D"."KGLRFHDL")
—
Then check a different server:
The query eventually completed on the 32 bit version of Oracle 10.2.0.2 with the Oracle October 2006 CPU.
PARSE 1|CPU S 0.000000|CLOCK S 0.006227|ROWs 0 EXEC 1|CPU S 0.000000|CLOCK S 0.000201|ROWs 0 FETCH 2|CPU S 13112.828125|CLOCK S 926.981803|ROWs 6 Row Source Execution Plan: (Rows 6) HASH UNIQUE (cr=0 pr=0 pw=0 time=568347223 us) (Rows 3463) NESTED LOOPS (cr=0 pr=0 pw=0 time=3464796755 us) (Rows 3463) NESTED LOOPS (cr=0 pr=0 pw=0 time=3464592419 us) (Rows 1613768) MERGE JOIN CARTESIAN (cr=0 pr=0 pw=0 time=21019488 us) (Rows 236) FIXED TABLE FULL X$KSUSE (cr=0 pr=0 pw=0 time=2376 us) (Rows 1613768) BUFFER SORT (cr=0 pr=0 pw=0 time=12951356 us) (Rows 6838) FIXED TABLE FULL X$KGLDP (cr=0 pr=0 pw=0 time=41073 us) (Rows 3463) FIXED TABLE FIXED INDEX X$KGLLK (ind:1) (cr=0 pr=0 pw=0 time=13094082350 us) (Rows 3463) FIXED TABLE FIXED INDEX X$KGLOB (ind:1) (cr=0 pr=0 pw=0 time=166548 us)
Note the merge Cartesian join between the 236 rows in X$KSUSE and the 1613768 rows from X$KGLDP.
The wait events:
0.03 seconds on latch: library cache
—
Then keep probing:
I may have found something that may help the OP – it hit me when I found very slow performance with the same SQL statement on 32 bit Oracle 10.2.0.3 and 11.1.0.6, after looking at the DBMS_XPLANs.
The DBMS_XPLAN on 10.2.0.3:
------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | OMem | 1Mem | Used-Mem |
------------------------------------------------------------------------------------------------------------------------
| 1 | HASH UNIQUE | | 1 | 105 | 5 |00:02:51.06 | | | |
| 2 | NESTED LOOPS | | 1 | 105 | 1131 |00:02:51.04 | | | |
| 3 | NESTED LOOPS | | 1 | 10 | 1131 |00:02:50.39 | | | |
| 4 | MERGE JOIN CARTESIAN | | 1 | 100 | 180K|00:00:01.27 | | | |
|* 5 | FIXED TABLE FULL | X$KSUSE | 1 | 1 | 236 |00:00:00.01 | | | |
| 6 | BUFFER SORT | | 236 | 100 | 180K|00:00:00.55 | 36864 | 36864 |32768 (0)|
| 7 | FIXED TABLE FULL | X$KGLDP | 1 | 100 | 763 |00:00:00.01 | | | |
|* 8 | FIXED TABLE FIXED INDEX| X$KGLLK (ind:1) | 180K| 1 | 1131 |00:02:48.31 | | | |
|* 9 | FIXED TABLE FIXED INDEX | X$KGLOB (ind:1) | 1131 | 10 | 1131 |00:00:00.64 | | | |
------------------------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
5 - filter("S"."INST_ID"=USERENV('INSTANCE'))
8 - filter(("L"."KGLLKUSE"="S"."ADDR" AND "L"."KGLLKHDL"="D"."KGLHDADR" AND "L"."KGLNAHSH"="D"."KGLNAHSH"))
9 - filter(("O"."KGLNAHSH"="D"."KGLRFHSH" AND "O"."KGLHDADR"="D"."KGLRFHDL"))
Note the MERGE JOIN CARTESIAN, and how the estimated rows compares with the actual rows.
The DBMS_XPLAN on 11.1.0.6:
select distinct owner from v$access
-------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | OMem | 1Mem | Used-Mem |
-------------------------------------------------------------------------------------------------------------------------
| 1 | HASH UNIQUE | | 1 | 1 | 6 |00:00:40.28 | 951K| 951K| 860K (0)|
| 2 | NESTED LOOPS | | 1 | 1 | 2342 |00:00:40.27 | | | |
| 3 | MERGE JOIN CARTESIAN | | 1 | 1 | 2842K|00:00:11.37 | | | |
| 4 | NESTED LOOPS | | 1 | 1 | 16721 |00:00:00.38 | | | |
| 5 | FIXED TABLE FULL | X$KGLDP | 1 | 100 | 16721 |00:00:00.05 | | | |
|* 6 | FIXED TABLE FIXED INDEX| X$KGLOB (ind:1) | 16721 | 1 | 16721 |00:00:00.21 | | | |
| 7 | BUFFER SORT | | 16721 | 1 | 2842K|00:00:02.91 | 4096 | 4096 | 4096 (0)|
|* 8 | FIXED TABLE FULL | X$KSUSE | 1 | 1 | 170 |00:00:00.01 | | | |
|* 9 | FIXED TABLE FIXED INDEX | X$KGLLK (ind:1) | 2842K| 1 | 2342 |00:00:15.49 | | | |
-------------------------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
6 - filter(("O"."KGLNAHSH"="D"."KGLRFHSH" AND "O"."KGLHDADR"="D"."KGLRFHDL"))
8 - filter("S"."INST_ID"=USERENV('INSTANCE'))
9 - filter(("L"."KGLLKUSE"="S"."ADDR" AND "L"."KGLLKHDL"="D"."KGLHDADR" AND "L"."KGLNAHSH"="D"."KGLNAHSH"))
The above executed more quickly, and the plan is slightly different, but the MERGE JOIN CARTESIAN is still present, as is the difference between the estimated and actual number of rows.
The fixed object stats must be wrong (I recall having a problem with that a couple years ago when perfoming the following)…
SQL> CONNECT / AS SYSDBA
SQL> EXEC DBMS_STATS.GATHER_FIXED_OBJECTS_STATS('ALL');
BEGIN DBMS_STATS.GATHER_FIXED_OBJECTS_STATS('ALL'); END;
*
ERROR at line 1:
ORA-20000: Insufficient privileges to analyze an object in Fixed Ob
ORA-06512: at "SYS.DBMS_STATS", line 17951
ORA-06512: at "SYS.DBMS_STATS", line 18404
ORA-06512: at "SYS.DBMS_STATS", line 18951
ORA-06512: at line 1
The same error occurs on Oracle 10.2.0.2, 10.2.0.3, and 11.1.0.6 as the internal user, SYS AS SYSDBA, and SYSTEM.
There must be another way:
SQL> EXEC DBMS_STATS.GATHER_SCHEMA_STATS('SYS',GATHER_FIXED=>TRUE)
PL/SQL PROCEDURE SUCCESSFULLY COMPLETED.
The new DBMS_XPLANs:
10.2.0.3:
-----------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | OMem | 1Mem | Used-Mem |
-----------------------------------------------------------------------------------------------------------------------
| 1 | HASH UNIQUE | | 1 | 7 | 4 |00:00:00.09 | | | |
| 2 | NESTED LOOPS | | 1 | 1822 | 1003 |00:00:00.08 | | | |
|* 3 | HASH JOIN | | 1 | 1822 | 1003 |00:00:00.05 | 898K| 898K| 1099K (0)|
|* 4 | HASH JOIN | | 1 | 1822 | 1897 |00:00:00.03 | 1010K| 1010K| 639K (0)|
|* 5 | FIXED TABLE FULL | X$KSUSE | 1 | 236 | 236 |00:00:00.01 | | | |
| 6 | FIXED TABLE FULL | X$KGLLK | 1 | 1822 | 1897 |00:00:00.01 | | | |
| 7 | FIXED TABLE FULL | X$KGLDP | 1 | 2892 | 649 |00:00:00.01 | | | |
|* 8 | FIXED TABLE FIXED INDEX| X$KGLOB (ind:1) | 1003 | 1 | 1003 |00:00:00.01 | | | |
-----------------------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
3 - access("L"."KGLLKHDL"="D"."KGLHDADR" AND "L"."KGLNAHSH"="D"."KGLNAHSH")
4 - access("L"."KGLLKUSE"="S"."ADDR")
5 - filter("S"."INST_ID"=USERENV('INSTANCE'))
8 - filter(("O"."KGLNAHSH"="D"."KGLRFHSH" AND "O"."KGLHDADR"="D"."KGLRFHDL"))
The MERGE JOIN CARTESIAN is gone and the execution time dropped from 2 minutes, 51 seconds to 0.09 seconds.
11.1.0.6:
------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | OMem | 1Mem | Used-Mem |
------------------------------------------------------------------------------------------------------------------------
| 1 | HASH UNIQUE | | 1 | 19 | 1 |00:00:00.04 | 1037K| 1037K| 368K (0)|
| 2 | NESTED LOOPS | | 1 | 1139 | 134 |00:00:00.04 | | | |
| 3 | NESTED LOOPS | | 1 | 1139 | 134 |00:00:00.03 | | | |
|* 4 | HASH JOIN | | 1 | 1139 | 1144 |00:00:00.02 | 1010K| 1010K| 1205K (0)|
|* 5 | FIXED TABLE FULL | X$KSUSE | 1 | 170 | 170 |00:00:00.01 | | | |
| 6 | FIXED TABLE FULL | X$KGLLK | 1 | 1139 | 1144 |00:00:00.01 | | | |
|* 7 | FIXED TABLE FIXED INDEX| X$KGLDP (ind:1) | 1144 | 1 | 134 |00:00:00.01 | | | |
|* 8 | FIXED TABLE FIXED INDEX | X$KGLOB (ind:1) | 134 | 1 | 134 |00:00:00.01 | | | |
------------------------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
4 - access("L"."KGLLKUSE"="S"."ADDR")
5 - filter("S"."INST_ID"=USERENV('INSTANCE'))
7 - filter(("L"."KGLLKHDL"="D"."KGLHDADR" AND "L"."KGLNAHSH"="D"."KGLNAHSH"))
8 - filter(("O"."KGLNAHSH"="D"."KGLRFHSH" AND "O"."KGLHDADR"="D"."KGLRFHDL"))
The MERGE JOIN CARTESIAN is gone and the execution time dropped from 40.28 seconds to 0.04 seconds.
The OP may be able to run the same DBMS_STATS.GATHER_SCHEMA_STATS procedure to work around the problem.
—
How to determine if I collected statistics on the fixed tables? A search on Metalink found this article from 2004:
https://metalink.oracle.com/metalink/plsql/f%3Fp%3D200:27:5000154048035945504::::p27_id,p27_show_header,p27_show_help:525959.996,1,1&usg=AFQjCNHJ_wI9tlazsGQ7AIUZ5RSlrp_8nw
(Edit: Note that the above link is gone in a Flash… If anyone is able to find the message on the Oracle support site -the site formerly known as Metalink, please let me know of the address.)
In the article, Jonathan Lewis mentioned that tab_stats$ could be checked.
Test database on 64 bit Windows:
SELECT * FROM SYS.TAB_STATS$
The above returned about 582 rows after running:
EXEC DBMS_STATS.GATHER_SCHEMA_STATS('SYS',GATHER_FIXED=>TRUE);
I then checked a production database, and found no rows returned. Using the suggestion from the Metalink article:
EXEC DBMS_STATS.GATHER_FIXED_OBJECTS_STATS(NULL);
The stats collection completed much more quickly, as it did not analyze the full SYS schema, and there were 582 rows returned by the query on SYS.TAB_STATS$. It looks like this simple query may be used to determine if fixed object statistics need to be collected.
Hi!
Could you explain please how you found hv=3250939240 ?
Thanks.
Alexander,
It has been a couple of years, but it appears that I performed the following steps:
Then I looked inside the 10046 trace file and found my SQL statement:
The first line shows: PARSING IN CURSOR #1 … hv=3250939240 ad=’8135a590′. The value that follows hv= is the hash value for the SQL statement. I just noticed that the blog article implies that the hash value is found on the WAIT lines, but that was not the intention of this comment (I worded this poorly) “On the waits, P1 is 13985, P2 is 214, P3 is 0, Buf is 99, SQL Hash is 3250939240”.
A multi-part series on 10046 trace files may be found here:
https://hoopercharles.wordpress.com/2009/12/01/10046-extended-sql-trace-interpretation/
Hi, Charles!
Thank you for reply!
Link, you gave me, was very usefull!
Let me ask you a question that I’d realy like to now. From time to time I see in my ASH reports ”latch: library cache” and “latch: shared pool”. Is it possible to track cause of such events using P1 from ASH report?
I played with “raw 10046”, dump library cache, but can’t find the way I can use P1 to find out “library cache object” waited for. Where I’ve lost ?
From your example:
WAIT #3: nam=’latch: library cache’ ela= 8566 address=1398554576 number=214 tries=1 obj#=-1 tim=5204643696
…so,
P1 = address = 1398554576
What is it use of that “address”? How can I found the root of problem?
Regards
I will state up front that I do not have the final answer – other people are welcome to offer their advice.
You might try a quick SQL statement:
My output looks like this:
I believe that you will find that if you convert the number 1398554576 found in the wait event to a hex number, it will be the same number as is what is displayed in the ADDR column of the above SQL statement. So, that probably did not help much. The wait time on that latch seems to be a little long at 0.008566 seconds – is it possible that the CPU utilization was atypically high on the server?
You might take a look at the following presentation that was created by Kyle Hailey – there are notes attached to some of the slides: http://www.perfvision.com/papers/10_libc.ppt
My notes on library cache and shared pool latches follow. The notes are mostly paraphrases from the Oracle documentation, for instance from the following page:
http://download.oracle.com/docs/cd/B19306_01/server.102/b14211/instance_tune.htm#sthref787
p1 (address) is the address of the latch, p2 (number) is the latch number, p3 (tries) is the number of times the process has slept waiting for the latch
A main cause of shared pool or library cache latch contention is parsing. For shared pool and library cache latches, possible causes include not using bind variables, insufficient size of application cursor cache, cursors closed explicitly after each execution, frequent log on/off, shared pool too small.
Examine the resource usage for related resources. For example, if the library cache latch is heavily contended for, then examine the hard and soft parse rates.
Examine the SQL statements for the sessions experiencing latch contention to see if there is any commonality.
For Shared pool,library cache
** Lack of statement reuse, Statements not using bind variables, Insufficient size of application cursor cache,
** Cursors closed explicitly after each execution, Frequent logon / logoffs,
** Underlying object structure being modified (for example truncate), Shared pool too small
* Look for:
** Sessions (in V$SESSTAT) with high:
** parse time CPU
** parse time elapsed
** Ratio of parse count (hard) / Execute Count
** Ratio of parse count (total) / Execute Count
* Cursors (in V$SQLAREA/V$SQLSTATS) with:
** High ratio of PARSE_CALLS / EXECUTIONS
** EXECUTIONS = 1 differing only in literals in the WHERE clause (that is, no bind variables used)
** High RELOADS
** High INVALIDATIONS
** Large (> 1mb) SHARABLE_MEM
You might be able to break the numbers down a little more by examining V$LATCH_CHILDREN:
Hi, Charles!
Thank you for answer!
OK, all those rules like decreasing parsing, using proper binds etc. it’s common investigation.
We can dig in it any time on running database, shooting SQLs using literals, or searching through v$sql_shared_cursors to find SQLs with non-shareable binds (due to changes in session’s nls settings etc)…
But the question, I’ve tried to understand is Why ASH reports shows us “latch: library cache” with P1, P2, P3. What use of those ones?
We are talking about events occurred in past time. How P1 could be useful for investigation? The only way I found to use it is query like:
select distinct sql_id from V$ACTIVE_SESSION_HISTORY
where sample_time between
to_timestamp(…..) and to_timestamp(…..) and
event = ‘latch: shared pool’ and
p1 = &P1 and
sql_id is not null;
But, again, what all those queries (we’ve found with above query) waiting for? Are they waiting just for allocating memory piece by P1 address? Why for this address? Short of shared memory?…
Best regards.
I believe that the P1 and P2 values (p1 (address) is the address of the latch, p2 (number) is the latch number) were retained with identical meaning when the “latch free” wait event was broken into multiple wait events in Oracle Database 10g. The p1 and p2 values of the “latch free” wait event were used to identify specifically which type of latch is causing delays. From the Oracle Database 9.2 Performance Tuning Guide, a SQL statement demonstrating the use of p2:
http://download.oracle.com/docs/cd/B10500_01/server.920/a96533/instance_tune.htm#12946
With the consideration of the above, the only meaningful piece of information provided, other than the specific latch name, is the number of sleeps while waiting for the latch to become available (p3 (tries) is the number of times the process has slept waiting for the latch).
There are a number of causes for shared pool latch contention and library cache latch contention. A couple of resources:
http://jonathanlewis.wordpress.com/2007/01/21/shared-sql/
http://jonathanlewis.wordpress.com/2008/12/23/library-cache/
http://jonathanlewis.wordpress.com/2007/01/05/bind-variables/
Also see discussion by Mark Bobak and Jonathan Lewis:
http://forums.oracle.com/forums/thread.jspa?messageID=9432629&tstart=0
—-
I am sure that you are aware, but I thought that it would good to mention for anyone else reading this article, that access to V$ACTIVE_SESSION_HISTORY and/or access to ASH and/or access to AWR and/or access to ADDM requires an Enterprise Edition license plus a Diagnostic Pack license.