Dion Cho – Oracle Performance Storyteller

We are natural born scientists

Tracking the bind value

with 14 comments

One of the most frequent questions I’m always asked of.

Can I trace the bind values of the SQL statement executed last night?

The answer is (sadly) NO.

As far as I know, we have only 2 ways

  • With session-wide or system-wide 10046 event(level >=4) enabled
  • With auditing enabled

But I bet that 99.99% of the system does not enable aboves.

Okay, then what else do we have? What comes into my mind is 1) Log Miner and/or 2) Bind Capture History.

1. Log Miner
In case of DML statements, you can retrieve the modified row information(NOT bind value!) from redo log fiie using log miner. This is extremely helpful for analyzing unique key violation problem, but not that meaningful for general bind value identification.

Simple demonstration:

UKJA@ukja102> create table t1(c1 int, c2 int, c3 char(100));

Table created.

UKJA@ukja102> insert into t1 select level, level, 'x'
  2  from dual connect by level <= 10000;

10000 rows created.

UKJA@ukja102> select log_mode from v$database;

LOG_MODE                                                                        
------------                                                                    
ARCHIVELOG                                                                      

UKJA@ukja102> alter system switch logfile;

System altered.

UKJA@ukja102> var b1 number;
UKJA@ukja102> var b2 number;
UKJA@ukja102> var b3 varchar2(1);
UKJA@ukja102> begin
  2    :b1 := 1;
  3    :b2 := 1000;
  4    :b3 := 'x';
  5  end;
  6  /

PL/SQL procedure successfully completed.

UKJA@ukja102> update t1 set c3 = :b3 where c1 between :b1 and :b2;

1000 rows updated.

UKJA@ukja102> commit;

Commit complete.

UKJA@ukja102> alter system switch logfile;

System altered.

UKJA@ukja102> col name new_value archive_file
UKJA@ukja102> select name from v$archived_log
  2  where sequence# = (select max(sequence#)rp from v$archived_log);

NAME                                                                            
------------------------------                                                  
C:\ORACLE\FLASH_RECOVERY_AREA\                                                  
UKJA10\ARCHIVELOG\2009_05_06\O                                                  
1_MF_1_4485_501WCW5V_.ARC                                                       
                                                                                

UKJA@ukja102> exec sys.dbms_logmnr.add_logfile('&archive_file');

PL/SQL procedure successfully completed.

UKJA@ukja102> exec sys.dbms_logmnr.start_logmnr;

PL/SQL procedure successfully completed.

UKJA@ukja102> col data_object_id new_value obj_id
UKJA@ukja102> select object_id, data_object_id from user_objects where object_name = 
'T1';

 OBJECT_ID DATA_OBJECT_ID                                                       
---------- --------------                                                       
     85083          85083                                                       

UKJA@ukja102> select count(*) from v$logmnr_contents
  2  where data_obj# = &obj_id;
old   2: where data_obj# = &obj_id
new   2: where data_obj# =      85083

  COUNT(*)                                                                      
----------                                                                      
     10033                                                                      

UKJA@ukja102> set serveroutput on
UKJA@ukja102> exec print_table('select * from v$logmnr_contents where -
>   operation = ''UPDATE'' and data_obj# = &obj_id and rownum = 1');
SCN                           : 8654960105647
CSCN                          :
TIMESTAMP                     : 2009/05/06 11:10:04
COMMIT_TIMESTAMP              :
THREAD#                       : 1
LOG_ID                        : 4486
XIDUSN                        : 1
XIDSLT                        : 29
XIDSQN                        : 18038
PXIDUSN                       : 1
PXIDSLT                       : 29
PXIDSQN                       : 18038
RBASQN                        : 4486
RBABLK                        : 2
RBABYTE                       : 192
UBAFIL                        : 2
UBABLK                        : 8388867
UBAREC                        : 24
UBASQN                        : 5559
ABS_FILE#                     : 2
REL_FILE#                     : 6
DATA_BLK#                     : 836
DATA_OBJ#                     : 85083
DATA_OBJD#                    : 85083
SEG_OWNER                     : UNKNOWN
SEG_NAME                      : OBJ# 85083
TABLE_NAME                    : OBJ# 85083
SEG_TYPE                      : 0
SEG_TYPE_NAME                 : UNKNOWN
TABLE_SPACE                   : UNKNOWN
ROW_ID                        : AAAUxbAAGAAAANEAAA
SESSION#                      : 0
SERIAL#                       : 0
USERNAME                      :
SESSION_INFO                  :
TX_NAME                       :
ROLLBACK                      : 0
OPERATION                     : UPDATE
OPERATION_CODE                : 3
SQL_REDO                      : update "UNKNOWN"."OBJ# 85083" set "COL 3" =
HEXTORAW('7820202020202020202020202020202020202020202020202020202020202020202020
20202020202020202020202020202020202020202020202020202020202020202020202020202020
20202020202020202020202020202020202020202020202020') where "COL 3" =
HEXTORAW('7820202020202020202020202020202020202020202020202020202020202020202020
20202020202020202020202020202020202020202020202020202020202020202020202020202020
20202020202020202020202020202020202020202020202020') and ROWID =
'AAAUxbAAGAAAANEAAA';
SQL_UNDO                      : update "UNKNOWN"."OBJ# 85083" set "COL 3" =
HEXTORAW('7820202020202020202020202020202020202020202020202020202020202020202020
20202020202020202020202020202020202020202020202020202020202020202020202020202020
20202020202020202020202020202020202020202020202020') where "COL 3" =
HEXTORAW('7820202020202020202020202020202020202020202020202020202020202020202020
20202020202020202020202020202020202020202020202020202020202020202020202020202020
20202020202020202020202020202020202020202020202020') and ROWID =
'AAAUxbAAGAAAANEAAA';
RS_ID                         :  0x001186.00000002.00c0
SEQUENCE#                     : 1
SSN                           : 0
CSF                           : 0
INFO                          : Dictionary Mismatch
STATUS                        : 2
REDO_VALUE                    : 2162
UNDO_VALUE                    : 2163
SQL_COLUMN_TYPE               :
SQL_COLUMN_NAME               :
REDO_LENGTH                   : 0
REDO_OFFSET                   : 0
UNDO_LENGTH                   : 0
UNDO_OFFSET                   : 0
DATA_OBJV#                    : 0
SAFE_RESUME_SCN               :
XID                           : 01001D0076460000
PXID                          : 01001D0076460000
AUDIT_SESSIONID               : 0
-----------------

PL/SQL procedure successfully completed.               

UKJA@ukja102> exec sys.dbms_logmnr.end_logmnr;

PL/SQL procedure successfully completed.




2. Bind Capture History
As of 10g, Oracle captures the bind value and stores it into the repository(AWR), but with following restrictions.

  • Captured periodically(_cursor_bind_capture_interval), not at real time.
  • Captured under maximum size(_cursor_bind_capture_area_size)
  • Only bind variables in WHERE clause are captured

Ouch! Too many restrictions, aren’t they?

Simple demonstration:

UKJA@ukja102> var bid1 number;
UKJA@ukja102> var eid1 number;
UKJA@ukja102> 
UKJA@ukja102> exec :bid1 := dbms_workload_repository.create_snapshot;

PL/SQL procedure successfully completed.

UKJA@ukja102> 
UKJA@ukja102> var b1 number;
UKJA@ukja102> var b2 number;
UKJA@ukja102> var b3 varchar2(1);
UKJA@ukja102> begin
  2    :b1 := 1;
  3    :b2 := 2000;
  4    :b3 := 'y';
  5  end;
  6  /

PL/SQL procedure successfully completed.

UKJA@ukja102> 
UKJA@ukja102> update t1 set c3 = :b3 where c1 between :b1 and :b2;

2000 rows updated.

UKJA@ukja102> commit;

Commit complete.

UKJA@ukja102> 
UKJA@ukja102> exec :eid1 := dbms_workload_repository.create_snapshot;

PL/SQL procedure successfully completed.

UKJA@ukja102> 
UKJA@ukja102> var sql_id varchar2(100);
UKJA@ukja102> begin
  2    select sql_id into :sql_id
  3    from dba_hist_sqltext
  4    where sql_text like 'update t1 set c3 = :b3 where c1 between :b1 and :b2';
  5  end;
  6  /

PL/SQL procedure successfully completed.

UKJA@ukja102> 
UKJA@ukja102> print sql_id

SQL_ID                                                                          
--------------------------------------------------------------------------------
bvy5d4xupjkku                                                                   

UKJA@ukja102> 
UKJA@ukja102> col name format a10
UKJA@ukja102> col position format 99
UKJA@ukja102> col value_string format a20
UKJA@ukja102> select snap_id, name, position, value_string, last_captured -
> from dba_hist_sqlbind
  2  where sql_id = :sql_id
  3  order by snap_id desc;

   SNAP_ID NAME       POSITION VALUE_STRING         LAST_CAPTURED               
---------- ---------- -------- -------------------- -------------------         
      6701 :B1               2 1                    2009/05/06 11:10:13         
      6701 :B2               3 2000                 2009/05/06 11:10:13         
      6701 :B3               1                                                  
      6700 :B2               3 1000                 2009/05/06 11:10:03         
      6700 :B3               1                                                  
      6700 :B1               2 1                    2009/05/06 11:10:03         
      6699 :B1               2 1                    2009/05/06 11:05:50         
      6699 :B3               1                                                  
      6699 :B2               3 2000                 2009/05/06 11:05:50         
      6697 :B2               3 2000                 2009/05/06 10:47:51         
      6697 :B3               1                                                  
      6697 :B1               2 1                    2009/05/06 10:47:51         

12 rows selected.





As I already pointed it out, these are just naive tries, not solution to the original question. Basically speaking, we have no ways to identify the bind values of the past SQL without 10046 event nor auditing enabled.




About these ads

Written by Dion Cho

May 7, 2009 at 6:07 am

14 Responses

Subscribe to comments with RSS.

  1. Try this out…won’t work if

    select b.username,
    c.name||'/'||c.value_string bind_var,
    sql_text from v$sqlarea a,
    --gv$sqlarea if in a RAC env.
    dba_users b,
    v$sql_bind_capture c --gv$sql_bind_capture if in a RAC env.
    where b.user_id=a.parsing_user_id
    and b.username != 'SYS'
    and c.address=a.address
    and a.address = :ADR
    order by 2

    Statistique

    May 7, 2009 at 6:21 pm

  2. Won’t work if your SQL is old but in an emergency this query can be very useful. Works under “Oracle Database 10g Enterprise Edition Release 10.2.0.3.0″

    Very sorry for the double post. :-(

    Statistique

    May 7, 2009 at 6:23 pm

  3. @Statistique.

    v$sql_bind_capture is nothing but the current version of dba_hist_sqlbind(so, has same restrictions) and available in the all versions >= 10g.

    Dion Cho

    May 8, 2009 at 12:29 am

  4. I am interesed to read your post. Do you have examples or previous post about using auditing to find bind value?

    denis

    May 18, 2009 at 6:53 pm

  5. @Denis

    Oracle has built up fantastic document on this.

    http://download.oracle.com/docs/cd/B28359_01/server.111/b28337/tdpsg_auditing.htm

    Dion Cho

    May 19, 2009 at 2:19 am

  6. Thanks. I will read the doc whenever having chances. My situation is I support a 9i database, which from time to time has blocker/waiter sessions (long enough to cause application slow down significantly). We are able to show dev team the sql of the blocking sessions. But they asked can you give us the bind values in those sqls? Then we lost. From your post, it seems possible to turn on audit on a table, then we can get bind value of the sql on it. Is it true? If so, looks to me better than turning on sql_trace, which is nearly impossible – we don’t know which and when a session will be blocking.

    denis

    May 19, 2009 at 2:36 pm

  7. @Denis

    In that case, FGA(Fine Grained Auditing) seems to be the solution.

    http://asktom.oracle.com/pls/asktom/f?p=100:11:0::::P11_QUESTION_ID:5967736255722

    http://download.oracle.com/docs/cd/B28359_01/appdev.111/b28419/d_fga.htm#CDEIECAG

    Dion Cho

    May 20, 2009 at 1:16 am

  8. IF your problem is still ongoing, meaning that the “bad” long-running statement is still running, the errorstack dump at level 2 would give you bind variable value as well (as I explained here: http://www.freelists.org/post/oracle-l/Tx-row-lock-contention-after-implementing-transaction-management-in-application-server,6 )

    Tanel Poder

    May 27, 2009 at 12:21 pm

  9. Thanks Tanel. I tested your method today: http://oracle-study-notes.blogspot.com/2009/05/oradebug-dump-errorstack-and-bind.html it should be helpful. Next time, if same situation occurs, I will give a try.

    FGA may work for 10g, but for 9i only SELECT is supported.

    Denis

    May 27, 2009 at 7:06 pm

  10. Bind values can be found together with other info in column OTHER_XML in V$SQL_PLAN or DBA_HIST_SQLPLAN in row with ID=0. They can by displayed (if available) with the option ADVANCED from

    V$SQL_PLAN:
    select * from table(dbms_xplan.display_cursor(‘&SQL_ID’,&child,’ADVANCED’));

    AWR:
    select * from table(dbms_xplan.display_awr(‘&SQL_ID’,NULL,NULL,’ADVANCED’));

    Petr

    July 28, 2009 at 10:48 am

    • Petr

      It’s technically impossible to get the bind values from shared v$ views and/or dictionary views. Bind values have meaning only at the session level(PGA), not the system level(SGA). This is why we have only 2 ways available to capture 100% of the bind values

      auditing
      10046 trace

      What you get from V$SQL_PLAN and DBA_HIST_SQLPLAN(and any other views) are the bind values of one specific session of one specific time.

      Dion Cho

      July 28, 2009 at 11:16 am

      • Hallo Dion,

        I supposed that peeked binds in OTHER_XML in v$sql_plan and dba_hist_sqlplan are the binds which were used when the statement was parsed.

        Petr

        July 29, 2009 at 7:38 am

        • Petr.

          Yes, I know that.
          But that’s not what I’m describing in this post. “Can we get the bind values used in the “select ..” query by session 146 10PM of last night?” – that’s the question here.

          Dion Cho

          July 29, 2009 at 7:45 am

  11. [...] other ASH / AWR resources: Tracking the bind variable – Dion Cho Doug’s AWR tagged posts Doug’s ASH tagged posts Possibly related posts: (automatically [...]


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 )

Google+ photo

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

Connecting to %s

Follow

Get every new post delivered to your Inbox.

Join 58 other followers

%d bloggers like this: