ANTONIO KLAUSS, June 14, 2002 - 4:45 pm UTC
Very useful piece of code. Thank you!
Much simpler way exists
Oleksandr Alesinskyy, October 28, 2002 - 5:22 pm UTC
In case of Delphi (and exactly this was in the orginal question) much simpler (while much less general) solutions exist. Delphi contain SQL*Monitor utility that do all that is needed. All that is needed to do - start this utility, turn on monitoring of bind variable values and specify logfile, then start application. All statements with all bind variable values ( both passed to DB and returned from it) would be in that file. This is true if application use BDE, in other case, if it use e.g. DOA, Debug property of DOA component that represent statement in question should be set to true (I'm not 100% sure about the property name -it may slightly differ, but it is very clear) and application recompiled. Then during application run before statement execution popup window with all bend variable values would appear.
Yours sincerely,
Oleksandr Alesinskyy
October 28, 2002 - 7:27 pm UTC
Excellent -- thanks!
Thanks for the insight
MDF, October 29, 2002 - 8:26 am UTC
The use of the Logon Trigger and "set events" was very
insightful. I can add this to my toolbox in the future...
We also use DOA (Direct Oracle Access) within Delphi,
and have used (extensively) the Oracle Monitor program
to watch SQL and Bind Variables as they are sent to
our Oracle database. It has saved us many hours of work
in tracking down problems...
Might be null -- any way to determine for certain?
Glenn A. Santa Cruz, March 17, 2003 - 1:04 pm UTC
Tom -
Is there any certain way to determine if the bind variable is null? You'd mentioned that an odd number in the oacflg value means the variable *might* be null; I presume the combination of odd oacflg and avl=00 would definitely mean a null value, but can we be certain about this? Could you show situations where oacflg is odd and the bind variable is not null?
Thanks
March 17, 2003 - 1:14 pm UTC
when I said "might be" -- it should be read as "could be, allowed to be"
the avl does it for you.
This may work
gs, March 17, 2003 - 3:27 pm UTC
Hope the following may work in 8.1.5
sql> connect / as sysdba ;
sql> oradebug setospid <SPID from v$process>
sql> oradebug event 10046 trace name context forever, level 4
I am not sure level 4 gives bind variables. But 12 definitely does
Tracing
Mike, March 18, 2003 - 12:48 am UTC
For what it's worth, set_ev() is another option that works well. It works for earlier version of 8 as well as 7.3. Of course, Tom's example via login trigger is ideal if you wish to capture all SQL vs. fighting the clock to find the session sid/serial and then executing the set_ev() or oradebug.
-- 1 Standard SQL_TRACE functionality
-- 4 As level 1 plus tracing of bind variables
-- 8 As level 1 plus wait events
-- 12 As level 1 plus bind variables and wait events.
execute sys.dbms_system.set_ev( <sid>,<serial>, 10046, 4, '');
fine
Vera, August 19, 2003 - 7:12 am UTC
Thanks. Very usefull.
Bind variables for application traceing 10g.
Rob, October 27, 2006 - 11:53 am UTC
Hi Tom,
we're using 10gR2, ProC, and loads of bind variables.
In case of error (sqlca.sqlcode!=0) in our application traces we trace the sql statements, but without the values for the binds it is not more than a hint.
It would be of much help, if we had the values for the binds as well.
For me (and from the documentation) it's unclear how I should use these views (or others):
V$SQL
V$SQL_BIND_CAPTURE
V$SQL_BIND_DATA
V$SQL_BIND_METADATA
to get the binds of the erratic sql statement (from the error handler ProC code).
1 Which view to select and how to join them?
2 How to find the last (erratic) statement of the current session?
3 How do things change with bulk/array operations?
Thanks a lot in advance,
Rob.
October 27, 2006 - 7:57 pm UTC
getting the "errant" sql statement is something you'll have to work on there - with the combination of dynamic sql, and parse once/execute many (eg; last parsed is NOT last executed). Might be useful to get the C source code file name, the lineno (easy macros to pass into default error handler) and a DUMP of ALL open cursors though.
ops$tkyte%ORA10GR2> variable x number
ops$tkyte%ORA10GR2> variable y varchar2(20)
ops$tkyte%ORA10GR2> variable z varchar2(20)
ops$tkyte%ORA10GR2> variable a refcursor
ops$tkyte%ORA10GR2>
ops$tkyte%ORA10GR2> exec :x := 42; :y := '01-jan-2006'; :z := 'Hello World'
PL/SQL procedure successfully completed.
ops$tkyte%ORA10GR2>
ops$tkyte%ORA10GR2> exec open :a for select * from t where x = :x and y = :y and z = :z;
PL/SQL procedure successfully completed.
ops$tkyte%ORA10GR2>
ops$tkyte%ORA10GR2> select b.sql_text, a.bind_vars, c.datatype, c.value
2 from v$sql_cursor a, v$sql b, v$sql_bind_data c
3 where b.address = a.parent_handle
4 and a.curno = c.cursor_num
5 /
SQL_TEXT
-------------------------------------------------------------------------------
BIND_VARS DATATYPE
---------- ----------
VALUE
-------------------------------------------------------------------------------
select b.sql_text, a.bind_vars, c.datatype, c.value from v$sql_cursor a, v$sq
l b, v$sql_bind_data c where b.address = a.parent_handle and a.curno = c.cu
rsor_num
0 0
SELECT * FROM T WHERE X = :B3 AND Y = :B2 AND Z = :B1
3 1
Hello World
SELECT * FROM T WHERE X = :B3 AND Y = :B2 AND Z = :B1
3 1
01-jan-2006
SELECT * FROM T WHERE X = :B3 AND Y = :B2 AND Z = :B1
3 2
42
Bind variables for application tracing 10g.
Rob, October 30, 2006 - 8:16 am UTC
Hi Tom,
thanks for the followup.
Following your guidelines we already have found the SQL statement, only the binds are missing:(
So here's our ProC sql statement (I expect the bind values between tags <START> and <END>):
SELECT
' SQL_TEXT: ' || A.sql_text ||
' CURSOR STATUS: ' || B.status ||
' CURSOR_NUM: ' || C.cursor_num ||
' BIND POSITION: ' || C.position ||
' BIND DATATYPE: ' || C.datatype ||
' BIND VARS (NUM): ' || B.bind_vars ||
' BIND VAR LOCATION: ' || B.bind_mem_loc ||
' BIND VALUE: <START>' || C.value || '<END>'
FROM
v$sql A,
v$sql_cursor B,
v$sql_bind_data C
WHERE
A.address = B.parent_handle and
C.cursor_num = B.curno;
And the output is 10 rows as
#1) have cursor_sharing=force,so the first 9 lines are the SYS binds similar to this:
SQL_TEXT: select ((((((((((((((((:"SYS_B_0"||A.sql_text)||:"SYS_B_1")||B.status)||:"SYS_B_2")||C.cursor_num)||:"SYS_B_3")||C.position)||:"SYS_B_4")||C.datatype)||:"SYS_B_5")||B.bind_vars)||:"SYS_B_6")||B.bind_mem_loc)||:"SYS_B_7")||C.value)||:"SYS_B_8") from v$sql A ,v$sql_cursor B ,v$sql_bind_data C where (A.address=B.parent_handle and C.cursor_num=B.curno)
CURSOR STATUS: CURFETCH
CURSOR_NUM: 1
BIND POSITION: 1
BIND DATATYPE: 1
BIND VARS (NUM): 9
BIND VAR LOCATION: UGA
BIND VALUE: <START> SQL_TEXT: <END>
#2) The important line is:
SQL_TEXT: insert into swm_idtversion (fdn,idtversion) values (:b0:b1,:b2)
CURSOR STATUS: CURBOUND
CURSOR_NUM: 2
BIND POSITION: 1
BIND DATATYPE: 1
BIND VARS (NUM): 2
BIND VAR LOCATION: UGA
BIND VALUE: <START><END>
So the binds are missing.
Other check I made was select * from v$sql_bind_data :
BIND CURSOR_NUM: 2
BIND POSITION: 1
BIND DATATYPE: 1
BIND SHARED_MAX_LEN: 2000
BIND PRIVATE_MAX_LEN: 202
ARRAY_SIZE 0
PRECISION 0
SCALE 0
SHARED_FLAG 1
SHARED_FLAG_2 16777217
BUF_ADDRESS 00
BUF_LENGTH 0
VAL_LENGTH 0
BUF_FLAG 0
INDICATOR 0
VALUE <blank>
I also gave I try with cursor_sharing = exact, with the same result.
Note:
- Here I can even see the length (202) of the variable, but not the value.
- I saw that cursor status = CURBOUND wich tells me that there should be a value for the bind somewhere
So could you please give me a hint on what I'm missing here?
Thanks,
Rob
October 30, 2006 - 9:26 am UTC
you are not missing anything, by the time you get around to looking, the information is gone that is all.
you are seeing the MAX_LEN, not the length.
that you are using cursor_sharing=force indicates you have a massive bug in your developed application of course, a big old bug, a huge bug - a security bug as well as a performance and scalability bug.
Bind variables for application tracing 10g.
A reader, October 30, 2006 - 10:01 am UTC
Thanks.
Why is it too late:)?
The errorhandler immediately after the execution of the problematic SQL dives into v$sql_bind_data and finds no value. It just cannot be done sooner. It is done right in the "WHENEVER SQLERROR ..." function
Q1) What is the trigger that removes the data from v$sql_bind_data? (E.g fix size filled up, or time elapsed)
Q2) If value is already gone then I would expect all values coming from v$sql_bind_data to be zero/null, but it is not the case:
SQL_TEXT: insert into swm_idtversion (fdn,idtversion)
values (:b0:b1,:b2)
CURSOR_NUM (v$sql_bind_data.cursor_num) : 2
BIND POSITION (v$sql_bind_data.position) : 1
BIND DATATYPE (v$sql_bind_data.datatype) : 1
BIND VALUE (v$sql_bind_data.value) : <START><END>
To me it is strange that only the value information is gone, but we see non-zero datatype and position. Do you know the reason? Could you explain?
Q3) How could I get the info before it gets removed? How could we possibly be faster (or slow down Oracle'c cleanup of v$sql_bind_data)?
Thanks in advance,
Rob
October 30, 2006 - 12:36 pm UTC
q1) not sure, just testing it shows "it isn't there by then". In my example above, the cursor was still actively OPEN.
q2) sorry, but it just isn't the case.
the datatype is "fixed" at parse time - if you bound with a different type - it would require an entirely different cursor (a new child cursor and all would be created in the shared pool). the datatype information is "constant" for that cursor, the bind values - are not.
q3) not sure, you might file a tar with support regarding that.
Bind variables for application tracing 10g
Rob, October 30, 2006 - 3:13 pm UTC
Thanks a lot for the explanation and your time!
It's a bad sign when you don't have the answers...
Last question (from my latest idea): Do you see a chance that ProC's HOLD_CURSOR, RELEASE_CURSOR parameters could
affect the "cleanup" issue?
R.
October 30, 2006 - 3:22 pm UTC
doubt it - since plsql caches cursors and my tests with plsql show "no", my inserts where "open" but the binds where not there.
But - worth a quick and dirty test on your part?
but since you are using cursor sharing force, does this mean you are doing mostly dynamic sql? perhaps we could take advantage of that (your code should have the sql statment in a string somewhere???)
Bind variables for application tracing 10g
Robert Koltai, November 10, 2006 - 11:32 am UTC
Hi Tom,
- Quick and dirty test result: it did not help
- We cannot use the "sql statement in string" as we need bind data exclusively in case of error, and we don't want to rewrite all our libraries, just the errorhandler
Anyway I modified, and extended your pl/sql code to reflect more our situation (e.g we try an insert that fails and then in the exception handling we select from v$ views)
drop table t;
create table t (x number (5), y varchar2(10));
set serveroutput on;
set linesize 150;
variable x number;
variable y varchar2(100);
begin -- THE BLOCK STARTS HERE :)
:x:= 123;
:y:= 'Hello World 123456787654321 dlroW olleH';
-- TRY THE WRONG INSERT AND CATCH THE EXCEPTION
begin
insert into t values (:x,:y);
exception
when others then
dbms_output.put_line ('******');
dbms_output.put_line ('I COUGHT THE INSERT EXCEPTION !!!');
dbms_output.put_line (sqlerrm || ' - HAPPENED');
dbms_output.put_line ('******');
-- RETRIEVE THE BINDS
for c_bind_record in (
select
substr(b.sql_text,1,55) sqltext ,
a.bind_vars var_number,
c.datatype var_type,
substr(c.value,1,40) var_value,
a.curno curno,
a.status status
from v$sql_cursor a, v$sql b, v$sql_bind_data c
where b.address = a.parent_handle
and a.curno = c.cursor_num
order by a.curno)
LOOP
dbms_output.put_line ('cursor ID : '|| c_bind_record.curno);
dbms_output.put_line ('cursor status: '|| c_bind_record.status);
dbms_output.put_line ('sqltext : '|| c_bind_record.sqltext);
dbms_output.put_line ('var_number : '|| c_bind_record.var_number);
dbms_output.put_line ('BIND VALUE : '|| c_bind_record.var_value);
dbms_output.put_line ('***');
END LOOP;
end; -- EXCEPTION HANDLING
end;
/
THIS IS WHAT I GET:
******
I COUGHT THE INSERT EXCEPTION !!!
ORA-12899: value too large for column "OMCDBSYS"."T"."Y" (actual: 39, maximum: 10) - HAPPENED
******
cursor ID : 3
cursor status: CURBOUND
sqltext : begin -- THE BLOCK STARTS HERE :) :x:= 123; :y:= '
var_number : 2
BIND VALUE : 123
***
cursor ID : 3
cursor status: CURBOUND
sqltext : begin -- THE BLOCK STARTS HERE :) :x:= 123; :y:= '
var_number : 2
BIND VALUE : Hello World 123456787654321 dlroW olleH
***
cursor ID : 4
cursor status: CURBOUND
sqltext : INSERT INTO T VALUES (:B1,:B2)
var_number : 2
BIND VALUE :
***
cursor ID : 5
cursor status: CURFETCH
sqltext : SELECT SUBSTR(B.SQL_TEXT,1,55) SQLTEXT , A.BIND_VARS VA
var_number : 0
BIND VALUE :
***
PL/SQL procedure successfully completed.
I noticed that the binds and the insert come from different cursor (curno). Can this be the difference between PL/SQL and ProC? Somehow PL/SQL has this extra implicit cursor that is not present in ProC?
THANKS.
November 10, 2006 - 2:48 pm UTC
plsql never closes your insert unless and until it absolutely has to. plsql caches them
Bind variables for application tracing 10g
Robert Koltai, November 10, 2006 - 12:36 pm UTC
Ciao Tom,
I think I understood it.
Check this version, and forget the previous one.
Concentrate on variable NOT_REAL_BIND.
What we select from v$sql_bind_data has nothing to do with the select that we want to monitor...
drop table t;
create table t (x number (5), y varchar2(10));
set serveroutput on;
set linesize 150;
variable x number;
variable y varchar2(100);
variable NOT_REAL_BIND varchar2(100); -- WE GET THIS BIND WHEREAS IT'S NOT MENTIONED IN OUR QUERY !
begin -- THE BLOCK STARTS HERE :)
:x:= 123;
:y:= 'Hello World 123456787654321 dlroW olleH';
:NOT_REAL_BIND:= '!!! THIS IS NOT A BIND IN MY SELECT !!!';
-- TRY THE WRONG INSERT AND CATCH THE EXCEPTION
begin
insert into t values (:x,:y);
exception
when others then
dbms_output.put_line ('******');
dbms_output.put_line ('I COUGHT THE INSERT EXCEPTION !!!');
dbms_output.put_line (sqlerrm || ' - HAPPENED');
dbms_output.put_line ('******');
-- RETRIEVE THE BINDS
for c_bind_record in (
select
substr(b.sql_text,1,55) sqltext ,
a.bind_vars var_number,
c.datatype var_type,
substr(c.value,1,40) var_value,
a.curno curno,
a.status status
from v$sql_cursor a, v$sql b, v$sql_bind_data c
where b.address = a.parent_handle
and a.curno = c.cursor_num
order by a.curno)
LOOP
dbms_output.put_line ('cursor ID : '|| c_bind_record.curno);
dbms_output.put_line ('cursor status: '|| c_bind_record.status);
dbms_output.put_line ('sqltext : '|| c_bind_record.sqltext);
dbms_output.put_line ('var_number : '|| c_bind_record.var_number);
dbms_output.put_line ('BIND VALUE : '|| c_bind_record.var_value);
dbms_output.put_line ('***');
END LOOP;
end; -- EXCEPTION HANDLING
end;
/
You see the
- 3 "binds" in cursor 1
- no bind in cursor 5
******
I COUGHT THE INSERT EXCEPTION !!!
ORA-12899: value too large for column "OMCDBSYS"."T"."Y" (actual: 39, maximum: 10) - HAPPENED
******
cursor ID : 1
cursor status: CURBOUND
sqltext : begin -- THE BLOCK STARTS HERE :) :x:= 123; :y:= '
var_number : 3
BIND VALUE : Hello World 123456787654321 dlroW olleH
***
cursor ID : 1
cursor status: CURBOUND
sqltext : begin -- THE BLOCK STARTS HERE :) :x:= 123; :y:= '
var_number : 3
BIND VALUE : !!! THIS IS NOT A BIND IN MY SELECT !!!
***
cursor ID : 1
cursor status: CURBOUND
sqltext : begin -- THE BLOCK STARTS HERE :) :x:= 123; :y:= '
var_number : 3
BIND VALUE : 123
***
cursor ID : 3
cursor status: CURFETCH
sqltext : SELECT SUBSTR(B.SQL_TEXT,1,55) SQLTEXT , A.BIND_VARS VA
var_number : 0
BIND VALUE :
***
cursor ID : 5
cursor status: CURBOUND
sqltext : INSERT INTO T VALUES (:B1,:B2)
var_number : 2
BIND VALUE :
***
PL/SQL procedure successfully completed.
What do you think?
Bye,
Robert
November 10, 2006 - 2:55 pm UTC
I'm not sure what exactly you want me to comment on
Bind variables for application tracing 10g
Robert Koltai, December 12, 2006 - 9:41 am UTC
Hi Tom,
you're right, I was not very clear with in my last comment.
A bit of a recap:
- You wrote a followup for "Bind variables for application traceing 10g. October 27, 2006". There you showed, that the binds can be retrieved using v$sql_cursor, v$sql, v$sql_bind_data in SQL*Plus environment.
- What I tried to demonstrate with my latest comment was, that your proof was incorrect I think.
My interpretation of my results is the following:
- Cursor 3 has no binds. This is the select on the v$ views
- Cursor 5 has no binds. This is the failing insert statement. I would expect the binds here.
- Cursor 1 has 3 binds of which NOT_REAL_BIND is not used in the insert, it is just a dummy. These 3 binds have nothing to do with the failing insert statement. These are just there because we bound them in the PL/SQL environment.
So this is why I think, that what you selected in your example, is not really what we were looking for. E.g.: those binds were not related to the failing insert statement.
I expect the binds for cursor 5, as they're part of that statement.
If I port this kind of error-handling to our Pro*C application, we don't have 'cursor 1' there. We simply see no binds in our application traces, and this result matches to my interpretation above.
Finally here are my questions:
1) do you agree with my interpretation? If not why?:))
2) from where could I get detailed information (more than what the Reference contains) on these v$ views? I would like to understand when/how they should be used.
Thanks a lot,
Robert
v$sql_bind_data explained (by Oracle Support)
Robert Koltai, January 26, 2007 - 11:02 am UTC
Hello,
after two months Oracle support came out with the reason why I can't see the binds in my select.
Excerpt:
"
V$SQL_BIND_DATA is based on GV$SQL_BIND_DATA
GV$SQL_BIND_DATA is based on fixed table x$kxsbd
x$kxsbd = [K]ernel E[X]ecution [S]hared Cursor [B]ind [D]ata
this makes clear that the V$SQL_BIND_DATA is only valid for CURSOR BINDS - and not for Insert, Update or Delete.
"
So far Oracle did not come up with a solution for being able to produce error traces containing the binds for the failed DML statement.
Is it really not possible with Oracle 10gR2?
Not in PL/SQL?
Not in ProC?
It's so hard to believe.
Tom your thoughts would be highly appreciated.
Regards,
Robert
bind_data
A reader, December 19, 2007 - 4:18 pm UTC
Tom,
In the v$sql view there is a column bind_data. Does this column contain the bind variable values for the SQL statement? If yes, then what is the format? I captured some of the information but it is a long hex string.
Thanks
December 20, 2007 - 9:47 am UTC
this decode will help you:
decode(datatype, 1, 'varchar2',
2, 'number',
8, 'LONG',
9, 'varchar',
12, 'DATE',
23, 'RAW', 24, 'LONG RAW',
69, 'ROWID',
96, 'char',
100, 'BINARY_FLOAT',
101, 'BINARY_DOUBLE',
105, 'MLSLABEL',
106, 'MLSLABEL',
112, 'clob',
113, 'BLOB', 114, 'BFILE', 115, 'CFILE',
180, 'TIMESTAMP',
181, 'TIMESTAMP WITH TIME ZONE',
231, 'TIMESTAMP WITH LOCAL TIME ZONE',
182, 'INTERVAL YEAR TO MONTH',
183, 'INTERVAL DAY TO SECOND',
208, 'UROWID',
'UNDEFINED')it can be many things in there. but mostly it should be viewable:
ops$tkyte%ORA10GR2> create or replace package foo
2 as
3 g_date date := sysdate;
4 g_num number := 42;
5 g_str varchar2(5) := 'hi';
6
7 cursor c is select * from dual where sysdate = g_date and 42 = g_num and 'hi' = g_str;
8 end;
9 /
Package created.
ops$tkyte%ORA10GR2> exec open foo.c;
PL/SQL procedure successfully completed.
ops$tkyte%ORA10GR2>
ops$tkyte%ORA10GR2> select v$sql_bind_data.*,
2 decode(datatype, 1, 'varchar2',
3 2, 'number',
4 8, 'LONG',
5 9, 'varchar',
6 12, 'DATE',
7 23, 'RAW', 24, 'LONG RAW',
8 69, 'ROWID',
9 96, 'char',
10 100, 'BINARY_FLOAT',
11 101, 'BINARY_DOUBLE',
12 105, 'MLSLABEL',
13 106, 'MLSLABEL',
14 112, 'clob',
15 113, 'BLOB', 114, 'BFILE', 115, 'CFILE',
16 180, 'TIMESTAMP',
17 181, 'TIMESTAMP WITH TIME ZONE',
18 231, 'TIMESTAMP WITH LOCAL TIME ZONE',
19 182, 'INTERVAL YEAR TO MONTH',
20 183, 'INTERVAL DAY TO SECOND',
21 208, 'UROWID',
22 'UNDEFINED')
23 from v$sql_bind_data where cursor_num = (select cursor_num from v$sql_bind_data where value = 'hi');
CURSOR_NUM POSITION DATATYPE SHARED_MAX_LEN PRIVATE_MAX_LEN ARRAY_SIZE
---------- ---------- ---------- -------------- --------------- ----------
PRECISION SCALE SHARED_FLAG SHARED_FLAG2 BUF_ADDR BUF_LENGTH VAL_LENGTH
---------- ---------- ----------- ------------ -------- ---------- ----------
BUF_FLAG INDICATOR
---------- ----------
VALUE
-------------------------------------------------------------------------------
DECODE(DATATYPE,1,'VARCHAR2',2
------------------------------
3 1 12 7 7 0
0 0 3 18898945 B72B423C 7 7
5 0
12/20/2007 9:53:26
DATE
3 2 2 22 21 0
0 0 3 18898945 B72B4244 22 2
1 0
42
number
3 3 1 32 5 0
0 0 3 18898945 B72B425C 32 2
1 0
hi
varchar2
bind_data
A reader, December 20, 2007 - 11:24 am UTC
Thanks, this is very useful.
Actually, I have captured the bind_data from v$sql and not from v$sql_bind_data. The query I used is:
select rawtohex(bind_data) from gv$sql where sql_id='0qn9wj10hj8yc';
The hex string looks like:
BEDA0A200300476917BB0014D8FF0FF00120001F00F00120001F00F00120001F00C00C0707786C061E010101F00120001F0432303038F00120001F0432303038F00120001F0432303038F00120001F00F00120001F00F00120001F0432303038F00120001F023233F00120001F023233F00120001F0131F00120001F0131F00120001F00F00120001F00
I was wondering if there is a way to find out the values of bind variables passed to the query from this string?
Thanks again...
December 20, 2007 - 2:32 pm UTC
this is for 10gr2 and up only.... dbms_xplan can do this (not documented, caveat emptor)
Let us set up a skewed table...
ops$tkyte%ORA10GR2> set linesize 1000
ops$tkyte%ORA10GR2> /*
ops$tkyte%ORA10GR2>
ops$tkyte%ORA10GR2> drop table skewed;
ops$tkyte%ORA10GR2>
ops$tkyte%ORA10GR2> create table skewed
ops$tkyte%ORA10GR2> as
ops$tkyte%ORA10GR2> select 99 id, a.*
ops$tkyte%ORA10GR2> from all_objects a
ops$tkyte%ORA10GR2> /
ops$tkyte%ORA10GR2> update skewed set id = 1 where rownum = 1;
ops$tkyte%ORA10GR2> create index skewed_idx on skewed(id);
ops$tkyte%ORA10GR2> exec dbms_stats.gather_table_stats( user, 'SKEWED', method_opt=> 'for all indexed columns size 254' );
ops$tkyte%ORA10GR2> */
Now, we are going to execute a query against this table, it should full scan given the bind input of 99:
ops$tkyte%ORA10GR2>
ops$tkyte%ORA10GR2> variable x number
ops$tkyte%ORA10GR2> set autotrace traceonly
ops$tkyte%ORA10GR2> exec :x := 99;
PL/SQL procedure successfully completed.
ops$tkyte%ORA10GR2> select * from skewed where id = :x;
50198 rows selected.
Execution Plan
----------------------------------------------------------
Plan hash value: 2941702783
----------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
----------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 50199 | 4706K| 237 (5)| 00:00:02 |
|* 1 | TABLE ACCESS FULL| SKEWED | 50199 | 4706K| 237 (5)| 00:00:02 |
----------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
1 - filter("ID"=TO_NUMBER(:X))
Statistics
----------------------------------------------------------
0 recursive calls
0 db block gets
4025 consistent gets
0 physical reads
0 redo size
2554667 bytes sent via SQL*Net to client
37191 bytes received via SQL*Net from client
3348 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
50198 rows processedand it would appear it does and all is well, however, later on, someone runs with id = 1, and notices the query is really poorly performing (because it was optimized with id=99 initially...)
ops$tkyte%ORA10GR2> exec :x := 1;
PL/SQL procedure successfully completed.
ops$tkyte%ORA10GR2> select * from skewed where id = :x;
Execution Plan
----------------------------------------------------------
Plan hash value: 2941702783
----------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
----------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 50199 | 4706K| 237 (5)| 00:00:02 |
|* 1 | TABLE ACCESS FULL| SKEWED | 50199 | 4706K| 237 (5)| 00:00:02 |
----------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
1 - filter("ID"=TO_NUMBER(:X))
Statistics
----------------------------------------------------------
0 recursive calls
0 db block gets
719 consistent gets
0 physical reads
0 redo size
1252 bytes sent via SQL*Net to client
385 bytes received via SQL*Net from client
2 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
1 rows processedso, they might turn on sql_trace to see what is taking so long, but.....
ops$tkyte%ORA10GR2> alter session set sql_trace=true;
Session altered.
ops$tkyte%ORA10GR2> select * from skewed where id = :x;
Execution Plan
----------------------------------------------------------
Plan hash value: 2941702783
----------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
----------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 50199 | 4706K| 237 (5)| 00:00:02 |
|* 1 | TABLE ACCESS FULL| SKEWED | 50199 | 4706K| 237 (5)| 00:00:02 |
----------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
1 - filter("ID"=TO_NUMBER(:X))
Statistics
----------------------------------------------------------
0 recursive calls
0 db block gets
4 consistent gets
0 physical reads
0 redo size
1252 bytes sent via SQL*Net to client
385 bytes received via SQL*Net from client
2 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
1 rows processed
ops$tkyte%ORA10GR2> set autotrace offwow, sql_trace made it go faster! (no, it didn't, sql_trace caused it to hard parse again)
http://asktom.oracle.com/Misc/tuning-with-sqltracetrue.html So, how can we see that - we review v$sql and find two cursors there:
ops$tkyte%ORA10GR2>
ops$tkyte%ORA10GR2> column sql_id new_val sql_id
ops$tkyte%ORA10GR2> select sql_id, sql_text, bind_data from v$sql where sql_text = 'select * from skewed where id = :x';
SQL_ID SQL_TEXT BIND_DATA
------------- ---------------------------------------- ----------------------------------------
2jux326p38h46 select * from skewed where id = :x BEDA0A200200476AC364000101C0021602C164
2jux326p38h46 select * from skewed where id = :x BEDA0A200200476AC365000101C0021602C102
we can use dbms_xplan to dump not only the plan - but using "advanced", lots more stuff - including decoding the bind_data used to optimize that query plan:
ops$tkyte%ORA10GR2>
ops$tkyte%ORA10GR2> SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR('&SQL_ID', 0, 'ADVANCED'));
old 1: SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR('&SQL_ID', 0, 'ADVANCED'))
new 1: SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR('2jux326p38h46', 0, 'ADVANCED'))
PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
SQL_ID 2jux326p38h46, child number 0
-------------------------------------
select * from skewed where id = :x
Plan hash value: 2941702783
----------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
----------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | | | 235 (100)| |
|* 1 | TABLE ACCESS FULL| SKEWED | 49844 | 6863K| 235 (4)| 00:00:02 |
----------------------------------------------------------------------------
Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------
1 - SEL$1 / SKEWED@SEL$1
Outline Data
-------------
/*+
BEGIN_OUTLINE_DATA
IGNORE_OPTIM_EMBEDDED_HINTS
OPTIMIZER_FEATURES_ENABLE('10.2.0.2')
ALL_ROWS
OUTLINE_LEAF(@"SEL$1")
FULL(@"SEL$1" "SKEWED"@"SEL$1")
END_OUTLINE_DATA
*/
Peeked Binds (identified by position):
--------------------------------------
1 - :X (NUMBER): 99
Predicate Information (identified by operation id):
---------------------------------------------------
1 - filter("ID"=:X)
Column Projection Information (identified by operation id):
-----------------------------------------------------------
1 - "ID"[NUMBER,22], "SKEWED"."OWNER"[VARCHAR2,30],
"SKEWED"."OBJECT_NAME"[VARCHAR2,30],
"SKEWED"."SUBOBJECT_NAME"[VARCHAR2,30],
"SKEWED"."OBJECT_ID"[NUMBER,22], "SKEWED"."DATA_OBJECT_ID"[NUMBER,22],
"SKEWED"."OBJECT_TYPE"[VARCHAR2,19], "SKEWED"."CREATED"[DATE,7],
"SKEWED"."LAST_DDL_TIME"[DATE,7], "SKEWED"."TIMESTAMP"[VARCHAR2,19],
"SKEWED"."STATUS"[VARCHAR2,7], "SKEWED"."TEMPORARY"[VARCHAR2,1],
"SKEWED"."GENERATED"[VARCHAR2,1], "SKEWED"."SECONDARY"[VARCHAR2,1]
Note
-----
- dynamic sampling used for this statement
57 rows selected.
ops$tkyte%ORA10GR2> SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR('&SQL_ID', 1, 'ADVANCED'));
old 1: SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR('&SQL_ID', 1, 'ADVANCED'))
new 1: SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_CURSOR('2jux326p38h46', 1, 'ADVANCED'))
PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
SQL_ID 2jux326p38h46, child number 1
-------------------------------------
select * from skewed where id = :x
Plan hash value: 2039504571
------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | | | 2 (100)| |
| 1 | TABLE ACCESS BY INDEX ROWID| SKEWED | 1 | 141 | 2 (0)| 00:00:01 |
|* 2 | INDEX RANGE SCAN | SKEWED_IDX | 1 | | 1 (0)| 00:00:01 |
------------------------------------------------------------------------------------------
Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------
1 - SEL$1 / SKEWED@SEL$1
2 - SEL$1 / SKEWED@SEL$1
Outline Data
-------------
/*+
BEGIN_OUTLINE_DATA
IGNORE_OPTIM_EMBEDDED_HINTS
OPTIMIZER_FEATURES_ENABLE('10.2.0.2')
ALL_ROWS
OUTLINE_LEAF(@"SEL$1")
INDEX(@"SEL$1" "SKEWED"@"SEL$1" ("SKEWED"."ID"))
END_OUTLINE_DATA
*/
Peeked Binds (identified by position):
--------------------------------------
1 - :X (NUMBER): 1
Predicate Information (identified by operation id):
---------------------------------------------------
2 - access("ID"=:X)
Column Projection Information (identified by operation id):
-----------------------------------------------------------
1 - "ID"[NUMBER,22], "SKEWED"."OWNER"[VARCHAR2,30],
"SKEWED"."OBJECT_NAME"[VARCHAR2,30], "SKEWED"."SUBOBJECT_NAME"[VARCHAR2,30],
"SKEWED"."OBJECT_ID"[NUMBER,22], "SKEWED"."DATA_OBJECT_ID"[NUMBER,22],
"SKEWED"."OBJECT_TYPE"[VARCHAR2,19], "SKEWED"."CREATED"[DATE,7],
"SKEWED"."LAST_DDL_TIME"[DATE,7], "SKEWED"."TIMESTAMP"[VARCHAR2,19],
"SKEWED"."STATUS"[VARCHAR2,7], "SKEWED"."TEMPORARY"[VARCHAR2,1],
"SKEWED"."GENERATED"[VARCHAR2,1], "SKEWED"."SECONDARY"[VARCHAR2,1]
2 - "SKEWED".ROWID[ROWID,10], "ID"[NUMBER,22]
Note
-----
- dynamic sampling used for this statement
59 rows selected.
Re: bind_data
dan kefford, December 20, 2007 - 2:41 pm UTC
I don't know if you would recommend doing this, Tom, but in your answer above, you could change your query to the following:
SELECT b1.*,
o1.name
FROM v$sql_bind_data b1,
sys.type$ t1,
sys.obj$ o1
WHERE b1.cursor_num =
(SELECT b2.cursor_num
FROM v$sql_bind_data b2
WHERE b2.value = '<<what you're looking for>>')
AND t1.typecode = b1.datatype
AND o1.oid$ = t1.toid
/
... to get the type descriptors. Gets rid of that nasty decode at any rate. :P
Thanks for this
Raja, June 18, 2008 - 8:13 am UTC
Hi Tom,
In 10g we are using v$sql_bind_capture to get the bind values. In case of 9i apart from the sql tracing method is there any other way around to find out the bind value of a bind variable.
Thanks
Also trying to find bind vars
Mette, July 23, 2008 - 5:54 am UTC
Hi
Repost from SQL forum, where noone answered - so now i'm trying here:
I am trying to extract BIND vars from the current or last SQL a session has produced:
The reason we try to do in in pure sql is that we are outsourced and the DBAs sits in another country. We dont have access to the actual servers (AIX) - thus we cannot run TKRPOF, 10046 traces etc. So we are kind of stuck
with pure SQL, and maybe a proxy
[Code]
select distinct name, value_string, datatype_string, last_captured, sql_text
from (
select rownum rn, DECODE (s.sql_id, NULL, s.prev_sql_id, s.sql_id) sql_id, sql_text
from v$session s, v$sqltext sq
where s.sid = :no and
DECODE (s.sql_hash_value, 0, s.prev_hash_value, s.sql_hash_value) = sq.hash_value and
DECODE (s.sql_id, NULL, s.prev_sql_id, s.sql_id) = sq.sql_id
union
select rownum rn, o.sql_id, sql_text
FROM v$open_cursor o, v$session s
WHERE o.saddr = s.saddr AND
o.SID = s.SID AND
s.sid = :no
) a, v$sql_bind_capture b
where a.sql_id = b.sql_id
order by last_captured desc nulls last;
[/Code]
This gives me a "better" result, since it takes the past executions from open cursors along, but I cant figure out if it takes too much if other sessions have executed the same SQL (same hash).
And since we have only sampled values it seems that it only takes the first execution of a statmets and its binds?
So ideas appreciated :-)
Best regards
Mette
PS rownum stuff is there, because it rewrites the query when we run it from the report in sql developer otherwise giving us terrible performance (2-3 minutes contra less 1 sec).
I know ....
Mette, July 28, 2008 - 4:26 pm UTC
... its a "self imposed restriction" - made by the UK DBA's from out outsourcing vendor :-)
But thanks for the hint of reading the trace files. Sometimes you just cant get that idea right.
I have now built a little trace package, so now I can make a trace, take the data from the trace file (and by parameter another trace file) and put it into either a table in a clob or into dbms_output.
Works great
Cheers
Mette
Quantity of bind variables exceeds table columns on insert
Hazel, June 19, 2012 - 6:34 pm UTC
Hi Tom
(rdbms 11.2.0.3) I have a trace file, that has an insert into a table with 64 named column:value pairs, however the trace entry is showing 67 bind fields. The underlying table has 70 columns. Do you know what the 3 extra bind fields could be? (the binds are null by the way). We are receiving a 12899 error and while it may seem that it should be obvious, it (painfully) is not.
Any insight would be very appreciated!
June 19, 2012 - 6:41 pm UTC
do you have the source code that does the binding? what language is it?
The 12899 wouldn't be caused by too many binds however - just one of the binds being too large and the error message should be telling you which one is too large and by how much.
Hazel, June 19, 2012 - 6:56 pm UTC
Yes, its written in plsql as a package. Have tried to dump the stack at runtime using exception when others and DBMS_UTILITY.FORMAT_ERROR_BACKTRACE but maybe I am not dumping entire stack to see entire message. Its a production site and I am being told that its failing just on the insert and of course, we can't reproduce in our development shop.
June 20, 2012 - 1:26 pm UTC
if you just let the exception PROPAGATE - do not catch it, just let it happen
you'll get the best error message *ever*.
get rid of the when others altogether.
Hazel, June 19, 2012 - 8:06 pm UTC
But my REAL curiousity is in why are there more fields being bound than involved with the basic dml statement? 64 named columns on insert, 67 binds and 70 columns in the table. I could understand constaint defaults, at the table level, maybe, but that is not the case as we have no default values if null defined against this table.
June 20, 2012 - 1:27 pm UTC
I'd have to see the example code.
bind variable values
Samuel, August 02, 2012 - 11:13 pm UTC
The application uses pl/sql code stored within the database. Almost all of the sqls have bind variables. How to find out the bind variable values of particular session when multiple sessions are coming with same sql id's. this is 10.2.0.4 database. Thanks.
Getting binds for parse errors
Shmyg, July 04, 2013 - 2:56 pm UTC
Hi Tom,
I've been using this technique for quite a while, but now I've got a case where SQL statement fails during the parsing, here is the message from the log-file:
PARSE ERROR #18446744071527991144:len=324 dep=0 uid=91 oct=2 lid=91 tim=1536367849020 err=917
insert into MPULKIXD (BILLSEQNO,BILL_PERIOD_END_DATE,REF_DATE,POSTING_PERIOD,DUE_DATE,BILLCYCLE,BILL_INFORMATION_IND,BILL_SIMULATION_IND,BILLING_MODE,POST_PROCESSED,REC_VERSION) values (:b1,TO_DATE(:b2:b3,:"SYS_B_0"),TO_DATE(:b4:b5,:"SYS_B_1"),:b6:b7,TO_DATE(:b8:b9,:"SYS_B_2"),:b10:b11,:b12,:b13,:b14,:"SYS_B_3",:"SYS_B_4")
And it throws ORA-00917 'Missing coma'. The thing is that I can't see the binds as the query itself is not executed. I'm pretty sure there is a space in one of the binds (most likely, :b10 or :b11, but how can I see those binds? I've tried everything I could imagine, triggers, V$sql_bind_capture, everything. No way.
July 16, 2013 - 1:19 pm UTC
give us the example to work with. create table, snippet of code to reproduce with.
I hate cursor_sharing=force/similar. ugh....
Serge Shmygelskyy, July 28, 2013 - 12:05 am UTC
Unfortunately, I can't extract the code, it's a proprietary application. But yes, the problem has been solved by changing cursor_sharing, though it seems strange to me the parameter could make the query fail - as per my understanding, it should only influence execution plan. Or is my understanding wrong?
August 02, 2013 - 5:32 pm UTC
we'd need a reproducible test case to play with to explain it, it looks "ok" to me:
ops$tkyte%ORA11GR2> drop table mpulkixd;
Table dropped.
ops$tkyte%ORA11GR2>
ops$tkyte%ORA11GR2> create table mpulkixd
2 (BILLSEQNO int,BILL_PERIOD_END_DATE int,REF_DATE int,POSTING_PERIOD int,DUE_DATE int,BILLCYCLE int,BILL_INFORMATION_IND
3 int,BILL_SIMULATION_IND int,BILLING_MODE int,POST_PROCESSED int,REC_VERSION int);
Table created.
ops$tkyte%ORA11GR2>
ops$tkyte%ORA11GR2>
ops$tkyte%ORA11GR2> explain plan for
2 insert into MPULKIXD
3 (BILLSEQNO,BILL_PERIOD_END_DATE,REF_DATE,POSTING_PERIOD,DUE_DATE,BILLCYCLE,BILL_INFORMATION_IND,BILL_SIMULATION_IND,BILLING_MODE,POST_PROCESSED,REC_VERSION) values
4 (:b1,TO_DATE(:b2:b3,:"SYS_B_0"),TO_DATE(:b4:b5,:"SYS_B_1"),:b6:b7,TO_DATE(:b8:b9,:"SYS_B_2"),:b10:b11,:b12,:b13,:b14,:"SYS_B_3",:"SYS_B_4")
5 /
Explained.