Unhandled datatype (-25) found in kxsbndinf — capturing bind variables

When dealing with a performance issue of a query, it’s important to know what bind variables are being used because Oracle’s bind variable peeking feature will make the optimizer to choose a different exeuction plan for different bind variables expecially with the adaptive cursor sharing feature introduced in 11g.

There are many ways to check bind variables being used. For example, using DBMS_XPLAN.DISPLAY_CURSOR with “ADVANCED” or “TYPICAL +PEEKED_BINDS” options:

SELECT * FROM TABLE (DBMS_XPLAN.DISPLAY_CURSOR('5v70gjmftwmg9',5, 'ADVANCED'));
select * from TABLE (DBMS_XPLAN.DISPLAY_CURSOR('5v70gjmftwmg9',5, format => 'TYPICAL +PEEKED_BINDS')); 

However for a timestamp column, the DBMS_XPLAN.DISPLAY_CURSOR way won’t work, you will see somthing like:

Peeked Binds (identified by position):
--------------------------------------
   1 - :1 (TIMESTAMP (TZ)): [Not Printable]
   2 - :2 (TIMESTAMP (TZ)): [Not Printable]

Another way is to use the view V$SQL_BIND_CAPTURE. For timestamp data, it will put into the column VALUE_ANYDATA which is ANYDATA data type, we could use the functions:

1. ANYDATA.ACCESSTIMESTAMP
2. ANYDATA.ACCESSTIMESTAMPTZ
3. ANYDATA.ACCESSTIMESTAMPLTZ

to access it. For example:

select child_number, name, POSITION, DATATYPE, DATATYPE_STRING, VALUE_STRING, was_CAPTURED, ANYDATA.ACCESSTIMESTAMP(VALUE_ANYDATA) datetime
from V$SQL_BIND_CAPTURE
where sql_id='5v70gjmftwmg9';

However, Oracle doesn’t capture bind variables for each execution and put them into V$SQL_BIND_CAPTURE because doing so is too expensive (thinking about those queries executed thousands times within a minute). So data in V$SQL_BIND_CAPTURE is just a sample data at the internval of 15 minutes which is controlled by the parameter “_cursor_bind_capture_interval”.

If you are fascinated to capture bind variables and above ways don’t work for you, the best bet is to use SQL trace.

You can enable the trace for a SQL statement with either dbms_monitor.session_trace_enable or using the traditional way 10046 event. Below is an eample:

ALTER SYSTEM SET EVENTS 'sql_trace [sql: sql_id=5v70gjmftwmg9] bind=true, wait=true';

or

ALTER SYSTEM SET EVENTS ‘sql_trace [sql: sql_id=5v70gjmftwmg9] level=12’;

After some time or monitoring the view v$sql to see query being executed, you can turn it off with

ALTER SYSTEM SET EVENTS 'sql_trace [sql: 5v70gjmftwmg9] off';

To locate the trace file generated, you either check the session information (780 is the session ID):

SELECT p.tracefile 
FROM  v$session s, v$process p, v$sql vs 
where s.paddr = p.addr and vs.address = s.sql_address and vs.sql_id='5v70gjmftwmg9';

SELECT p.tracefile FROM   v$session s JOIN v$process p ON s.paddr = p.addr WHERE  s.sid = 780;

Or just go to your diag trace directory and search for the sql_id within the trace file:

[oracle@joetestDB trace]$ grep -i 5v70gjmftwmg9 *.trc
PROD_ora_3811921.trc:PARSING IN CURSOR #140711835434824 len=205 dep=0 uid=34 oct=3 lid=34 tim=1598092683436 hv=3718139369 ad='357919db8' sqlid='5v70gjmftwmg9'

Note, the file will have tha recent timestamp (updated time) and the file name actually contains the process ID (3811921 is the OS process ID).

Then you can inspect the raw trace file (note tkprof tool doesn’t extract bind variables).

BINDS #140711835434824:

 Bind#0
  oacdty=231 mxl=11(07) mxlc=00 mal=00 scl=09 pre=00
  oacflg=00 fl2=9000000 frm=00 csi=00 siz=32 off=0
  kxsbbbfp=7ffa06d29860  bln=11  avl=07  flg=05
  value=Unhandled datatype (-25) found in kxsbndinf
Dumping '' addr=0x7ffa06d29860 size=7 bytes
Dump of memory from 0x7ffa06d29860 to 0x7ffa06d29868
7FFA06D29860 06067678 00010106                    [xv......]
 Bind#1
  oacdty=231 mxl=11(07) mxlc=00 mal=00 scl=09 pre=00
  oacflg=00 fl2=9000000 frm=00 csi=00 siz=0 off=16
  kxsbbbfp=7ffa06d29870  bln=11  avl=07  flg=01
  value=Unhandled datatype (-25) found in kxsbndinf
Dumping '' addr=0x7ffa06d29870 size=7 bytes
Dump of memory from 0x7ffa06d29870 to 0x7ffa06d29878
7FFA06D29870 05067678 00010106                    [xv......]

In the example above, unfortunately even the trace didn’t really tell what bind variables were used. It just saying:

value=Unhandled datatype (-25) found in kxsbndinf

“oacdty=231” actually tells it has the data type 231 which is “TIMESTAMP [(fractional_seconds_precision)] WITH LOCAL TIME ZONE“. The column DATATYPE in the view V$SQL_BIND_CAPTURE also shows 231.

I am not able to find any explaination why Oracle would say “Unhandled datatype” here.

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out /  Change )

Twitter picture

You are commenting using your Twitter account. Log Out /  Change )

Facebook photo

You are commenting using your Facebook account. Log Out /  Change )

Connecting to %s