Страницы

понедельник, 22 декабря 2014 г.

c3p0 PROBABLYNOT connection test query

I am participating in the project, which uses Play framework version 1.x.
Business logic at the application level, data stored in the Oracle database.
An SQL query below caught my attention:
--sql_id=az33m61ym46y4
SELECT NULL AS table_cat,
       o.owner AS table_schem,
       o.object_name AS table_name,
       o.object_type AS table_type,
       NULL AS remarks
  FROM all_objects o
  WHERE o.owner LIKE :1 ESCAPE '/'
    AND o.object_name LIKE :2 ESCAPE '/'
    AND o.object_type IN ('xxx', 'TABLE')
  ORDER BY table_type, table_schem, table_name
This query was executed 100K times per hour.
I enable SQL trace for a short time period to help diagnose this issue further:
alter system set events 'sql_trace[sql:az33m61ym46y4] bind=true';
"Bad" query was executed by different users but has same bind variable data:
BINDS #18446744071469205160:
Bind#0
  oacdty=01 mxl=32(04) mxlc=00 mal=00 scl=00 pre=00
  oacflg=03 fl2=1000010 frm=01 csi=873 siz=160 off=0
  kxsbbbfp=ffffffff7a760438  bln=32  avl=01  flg=05
  value="%"
Bind#1
  oacdty=01 mxl=128(44) mxlc=00 mal=00 scl=00 pre=00
  oacflg=03 fl2=1000010 frm=01 csi=873 siz=0 off=32
  kxsbbbfp=ffffffff7a760458  bln=128  avl=11  flg=01
  value="PROBABLYNOT"
Looks like we are faced with a c3p0 default connection test query.
Play framework uses the popular c3p0 for its connection pool. This query could be changed for something lightweight, such as:
select 'x' from dual
I sent that information to Java programmers and they promised to fix this issue.

вторник, 16 сентября 2014 г.

Bug 4991675 - Diagnostic event improve diagnosability of data dictionary invalidation issues

In recent MOS HOT Topics email I found a note: Bug 4991675 - Diagnostic event improve diagnosability of data dictionary invalidation issues (Doc ID 4991675.8) Many DBAs faced with "sporadic" invalidation issues in their work. Finding a root cause for such issues is not always easy. In many cases we investigate audit records, process redo logs with LogMiner and so on. You are out of problem when there are no DDL in database. Unfortunately, such goal not always reachable. In patch readme you can find next notes:
Note:Patch Post Install Steps:
This fix enhances the _trace_kqlidp parameter therefore please set this
parameter to true to enable this fix.
_trace_kqlidp was probably introduced in 11.1 but this patch enhances the parameter. I wrote a simple test case that can be used to demonstrate the effect of _trace_kqlidp parameter.
def tns_alias=orcl

conn /@&tns_alias.
drop user tc cascade;
grant connect to tc identified by tc;
grant alter session, create procedure, create table to tc;

conn tc/tc@&tns_alias.

create table t(x int) segment creation deferred;

create or replace procedure p
is
begin
  for t_rec in (
    select * from t)
  loop
    null;
  end loop;
end;
/

alter session set "_trace_kqlidp"=true;

select status from obj where object_name='P';
alter table t add y int;
select status from obj where object_name='P';
Latest alter table invalidates the procedure P. With parameter _trace_kqlidp set I see in trace file on 11.2.0.3:
ksedsts()+1296<-kqlidp0()+12068<-atbdrv()+26728<-opiexe()+20544<-opiosq0()+5576<-kpooprx()+212<-kpoal8()+536<-opiodr()+1164<-ttcpip()+1104<-opitsk()+1664<-opiino()+924<-opiodr()+1164<-opidrv()+1032<-sou2o()+88<-opimai_real()+504<-ssthrdmain()+316<-main()+316
<-_start()+380Fine-grain delta dump for unit TC.T
- Change bit vector 0:
  -23, -16, 
- Change bit vector 1:Empty
- Change bit vector 2:Empty
- Shift table:Empty 
kqlidp0: 964375 (CURSOR TC.T) (Parent:    0) [ROOT]
kqlidp0:. 964376 (PROCEDURE TC.P) (Parent:964375) [ADDED TO QUEUE]
kqlidp0:. 964376 (PROCEDURE TC.P) (Parent:964375) [INVALIDATE]
On 12.1.0.2:
INVALIDATION: Current SQL follows
alter table t add y int
ksedsts()+392<-kqlidp0()+11984<-atbdrv()+6728<-opiexe()+22596<-opiosq0()+3928<-kpooprx()+196<-kpoal8()+656<-opiodr()+1100<-ttcpip()+972<-opitsk()+1820<-opiino()+920<-opiodr()+1100<-opidrv()+932<-sou2o()+112<-opimai_real()+756<-ssthrdmain()+456<-main()+320<-_start()+300
Fine-grain delta dump for unit TC.T
- Change bit vector 0:
  -23, -16, 
- Change bit vector 1:Empty
- Change bit vector 2:Empty
- Shift table:Empty 
kqlidp0: 91877 (CURSOR TC.T) (Parent:    0) [ROOT]
kqlidp0:. 91878 (PROCEDURE TC.P) (Parent:91877) [ADDED TO QUEUE]
kqlidp0:. 91878 (PROCEDURE TC.P) (Parent:91877) [INVALIDATE]
We can see that patch 4991675 probably adds highlighted lines. "INVALIDATION" line helps in trace file identification. "Current SQL" line simplify root cause analysis. Update: alert.log also populated with "INVALIDATION" line.
Tue Sep 16 10:16:50 2014
INVALIDATION performed by ospid=21919. Please see tracefile.

суббота, 23 августа 2014 г.

event 10505

[oracle@oracle ~]$ oerr ora 10505
10505, 00000, "CBO enable dynamic sampling dump to table"
// *Cause:
// *Action:
Event 10505 can be used to dump dynamic sampling data to table. Same information can be obtained from event 10053 trace files. This event requires additional tables:
-- general table and dynamic sampling stats
create table kkedsamp_table(
  table_name varchar2(30),
  dyn_sampling_level number,
  c3 number, -- unknown
  c4 number, -- unknown
  c5 number, -- unknown
  c6 number, -- unknown
  c7 number, -- unknown
  single_table_dyn_sel_est number,
  dynamic_sampling_card number,
  sample_pct number,
  c11 number, -- unknown, partitioning
  c12 number, -- unknown, partitioning
  c13 number, -- unknown, partitioning
  c14 number, -- unknown
  actual_sample_size number,
  filtered_sample_card number,
  orig_card number,
  block_cnt_for_sampling_tabstat number,
  c19 number,
  max_sample_block_cnt number,
  sample_block_cnt number,
  min_sel_est number);
-- column stats
create table kkedsamp_column(
  column_name varchar2(30),
  table_name varchar2(30),
  c3 number, -- unknown
  num_distinct number,
  num_distinct_scaled number,
  num_nulls number,
  num_nulls_scaled number);
-- index stats
create table kkedsamp_index(
  index_name varchar2(30),
  table_name varchar2(30),
  c3 number, -- unknown
  index_selectity_est number,
  min_sel_est number, 
  c6 number, -- unknown
  num_blocks number);
Test case (run on 11.2.0.3):
SQL> create table t1 as select * from dba_objects;

Table created.
SQL> create table t2 as select * from dba_objects;

Table created.
SQL> create index t1_subobject_name_i on t1(subobject_name);

Index created.
SQL> exec dbms_stats.delete_index_stats( '', 'T1_SUBOBJECT_NAME_I')

PL/SQL procedure successfully completed.
SQL> alter session set events '10505';

Session altered.
SQL> select /*+ dynamic_sampling(4)*/
  2         count(*)
  3    from t1, t2
  4   where t1.owner='SYSTEM'
  5     and t2.subobject_name=t1.subobject_name
  6     and t2.object_type like 'TABLE%';

  COUNT(*)
----------
      3425
SQL> alter session set events '10505 off';

Session altered.
SQL> @pt "select * from kkedsamp_table"
TABLE_NAME                    : "T1"
DYN_SAMPLING_LEVEL            : 4
C3                            : 1
C4                            : 1
C5                            : 1
C6                            : 1
C7                            : 1
SINGLE_TABLE_DYN_SEL_EST      : .060506329113924
DYNAMIC_SAMPLING_CARD         : 12665.0793650794
SAMPLE_PCT                    : 31.1881188118812
C11                           : 1
C12                           : 1
C13                           : 1
C14                           : 1
ACTUAL_SAMPLE_SIZE            : 3950
FILTERED_SAMPLE_CARD          : 239
ORIG_CARD                     : 16500
BLOCK_CNT_FOR_SAMPLING_TABSTAT: 202
C19                           : 0
MAX_SAMPLE_BLOCK_CNT          : 64
SAMPLE_BLOCK_CNT              : 63
MIN_SEL_EST                   : .01
-----------------
TABLE_NAME                    : "T2"
DYN_SAMPLING_LEVEL            : 4
C3                            : 1
C4                            : 1
C5                            : 1
C6                            : 1
C7                            : 0
SINGLE_TABLE_DYN_SEL_EST      : .135717785399314
DYNAMIC_SAMPLING_CARD         : 13088.3174603175
SAMPLE_PCT                    : 31.1881188118812
C11                           : 1
C12                           : 1
C13                           : 1
C14                           : 1
ACTUAL_SAMPLE_SIZE            : 4082
FILTERED_SAMPLE_CARD          : 554
ORIG_CARD                     : 16500
BLOCK_CNT_FOR_SAMPLING_TABSTAT: 202
C19                           : 0
MAX_SAMPLE_BLOCK_CNT          : 64
SAMPLE_BLOCK_CNT              : 63
MIN_SEL_EST                   : .05
-----------------

PL/SQL procedure successfully completed.
SQL> @pt "select * from kkedsamp_column"
COLUMN_NAME                   : "T1"."SUBOBJECT_NAME"
TABLE_NAME                    : "T1"
C3                            : 3
NUM_DISTINCT                  : 160
NUM_DISTINCT_SCALED           : 161
NUM_NULLS                     : 3699
NUM_NULLS_SCALED              : 11860.2857142857
-----------------
COLUMN_NAME                   : "T2"."SUBOBJECT_NAME"
TABLE_NAME                    : "T2"
C3                            : 3
NUM_DISTINCT                  : 66
NUM_DISTINCT_SCALED           : 66
NUM_NULLS                     : 3997
NUM_NULLS_SCALED              : 12815.7777777778
-----------------

PL/SQL procedure successfully completed.
SQL> @pt "select * from kkedsamp_index"
INDEX_NAME                    : T1_SUBOBJECT_NAME_I
TABLE_NAME                    : "T1"
C3                            : 0
INDEX_SELECTITY_EST           : -1
MIN_SEL_EST                   : -1
C6                            : 1
NUM_BLOCKS                    : 8
-----------------
PL/SQL procedure successfully completed.

воскресенье, 3 августа 2014 г.

JPPD bypassed View has non-standard group by

В одной из БД Hibernate сгенерировал новый запрос, который вызвал повышенную загрузку. Я исследовал этот запрос, оптимизируется он легко, но я выявил один интересный случай, когда JPPD (join-predicate push-down) не срабатывает для group by view. Test case (11.2.0.3):
drop table t1 cascade constraints purge;
drop table t2 cascade constraints purge;
create table t1(x,y) as select rownum, rownum from dual connect by level<=1e4;
alter table t1 modify x not null;
create index t1_y_i on t1(y);
create table t2(x,z) as select rownum, cast(dummy as char(20)) from dual connect by level<=1e5;
alter table t2 modify x not null;
create index t2_x_i on t2(x);
exec dbms_stats.gather_table_stats( '', 't1')
exec dbms_stats.gather_table_stats( '', 't2')
Hibernate генерировал следующий запрос:
select *
  from t1
 where y = :1
   and x not in (select x from t2 group by x);
С планом:
---------------------------------------------------------------------------------------
| Id  | Operation                    | Name   | Rows  | Bytes | Cost (%CPU)| Time     |
---------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT             |        |     1 |     8 |    85  (25)| 00:00:02 |
|*  1 |  FILTER                      |        |       |       |            |          |
|   2 |   TABLE ACCESS BY INDEX ROWID| T1     |     1 |     8 |     2   (0)| 00:00:01 |
|*  3 |    INDEX RANGE SCAN          | T1_Y_I |     1 |       |     1   (0)| 00:00:01 |
|*  4 |   FILTER                     |        |       |       |            |          |
|   5 |    HASH GROUP BY             |        |     1 |     5 |    83  (26)| 00:00:01 |
|   6 |     INDEX FAST FULL SCAN     | T2_X_I |   100K|   488K|    65   (5)| 00:00:01 |
---------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
   1 - filter( NOT EXISTS (SELECT 0 FROM "T2" "T2" GROUP BY "X" HAVING
              "X"=:B1))
   3 - access("Y"=TO_NUMBER(:1))
   4 - filter("X"=:B1)
Условие по T1 (Y=:1) - очень селективное. Как видно, subquery unnesting не срабатывает, а хотелось бы видеть анти-соединение, использующее INDEX RANGE SCAN индекса T2_X_I (индекс по T2(X)). Рассмотрим эквивалентный запрос:
select *
  from t1
 where y = :1
   and x not in (select x from t2);
Его план, который бы хотелось получить для исходного запроса:
---------------------------------------------------------------------------------------
| Id  | Operation                    | Name   | Rows  | Bytes | Cost (%CPU)| Time     |
---------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT             |        |     1 |    13 |     3   (0)| 00:00:01 |
|   1 |  NESTED LOOPS ANTI           |        |     1 |    13 |     3   (0)| 00:00:01 |
|   2 |   TABLE ACCESS BY INDEX ROWID| T1     |     1 |     8 |     2   (0)| 00:00:01 |
|*  3 |    INDEX RANGE SCAN          | T1_Y_I |     1 |       |     1   (0)| 00:00:01 |
|*  4 |   INDEX RANGE SCAN           | T2_X_I |   100K|   488K|     1   (0)| 00:00:01 |
---------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
   3 - access("Y"=TO_NUMBER(:1))
   4 - access("X"="X")
Как еще можно переписать запрос? По логике, нужно выбрать строки из T1, которых нет в T2. Такой запрос с Oracle синтаксисом Join:
select t1.*
  from t1,
       (select x 
          from t2 
         group by x) t2
 where y = :1
   and t1.x = t2.x(+)
   and t2.x is null;
Имеет план:
-----------------------------------------------------------------------------------------------
| Id  | Operation                    | Name   | Rows  | Bytes |TempSpc| Cost (%CPU)| Time     |
-----------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT             |        |     1 |    21 |       |   233   (4)| 00:00:03 |
|*  1 |  HASH JOIN ANTI              |        |     1 |    21 |       |   233   (4)| 00:00:03 |
|   2 |   TABLE ACCESS BY INDEX ROWID| T1     |     1 |     8 |       |     2   (0)| 00:00:01 |
|*  3 |    INDEX RANGE SCAN          | T1_Y_I |     1 |       |       |     1   (0)| 00:00:01 |
|   4 |   VIEW                       |        |   100K|  1269K|       |   228   (3)| 00:00:03 |
|   5 |    HASH GROUP BY             |        |   100K|   488K|  1192K|   228   (3)| 00:00:03 |
|   6 |     INDEX FULL SCAN          | T2_X_I |   100K|   488K|       |   228   (3)| 00:00:03 |
-----------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
   1 - access("T1"."X"="T2"."X")
   3 - access("Y"=TO_NUMBER(:1))
Мы видим, что происходит HASH JOIN ANTI (анти-соединение) без JPPD. Т.е. предикат соединения T1.X=T2.X - не был протолкнут внутрь GROUP BY VIEW по T2. Выполнить проталкивание хинтами не получилось, что говорит о том, что такое VIEW для JPPD не подходит. Пришлось обратиться к трассировке CBO в поисках причин.
JPPD:     JPPD bypassed: View has non-standard group by.
JPPD: Applying transformation directives
JPPD: Checking validity of push-down in query block SEL$6D455ABB (#1)
JPPD:   No valid views found to push predicate into.
Вот это уже информация для анализа. Мы видим, что JPPD не сработал, т.к. View: "has non-standard group by". Подумав, я написал следующий запрос:
select t1.*
  from t1,
       (select x, 
               count(*)
          from t2 
         group by x) t2
 where y=:1
   and t1.x = t2.x(+)
   and t2.x is null;
Его план:
---------------------------------------------------------------------------------------
| Id  | Operation                    | Name   | Rows  | Bytes | Cost (%CPU)| Time     |
---------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT             |        |     1 |    10 |     3   (0)| 00:00:01 |
|   1 |  NESTED LOOPS ANTI           |        |     1 |    10 |     3   (0)| 00:00:01 |
|   2 |   TABLE ACCESS BY INDEX ROWID| T1     |     1 |     8 |     2   (0)| 00:00:01 |
|*  3 |    INDEX RANGE SCAN          | T1_Y_I |     1 |       |     1   (0)| 00:00:01 |
|   4 |   VIEW PUSHED PREDICATE      |        |     1 |     2 |     1   (0)| 00:00:01 |
|   5 |    SORT GROUP BY             |        |     1 |     5 |     1   (0)| 00:00:01 |
|*  6 |     INDEX RANGE SCAN         | T2_X_I |     1 |     5 |     1   (0)| 00:00:01 |
---------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
   3 - access("Y"=TO_NUMBER(:1))
   6 - access("X"="T1"."X")
По сути дела, мы запрос:
select t1.*
  from t1,
       (select x 
          from t2 
         group by x) t2
 where y = :1
   and t1.x = t2.x(+)
   and t2.x is null;
Переписали в эквивалентный:
select t1.*
  from t1,
       (select x, 
               count(*) 
          from t2 
         group by x) t2
 where y=:1
   and t1.x = t2.x(+)
   and t2.x is null;
И это позволило выполнить JPPD, что видно в плане и в трассе CBO:
***********************************
Cost-Based Join Predicate Push-down
***********************************
JPPD: Checking validity of push-down in query block SEL$6D455ABB (#1)
JPPD:   Checking validity of push-down from query block SEL$6D455ABB (#1) to query block SEL$2 (#2)
Check Basic Validity for Non-Union View for query block SEL$2 (#2)
JPPD:     Passed validity checks
JPPD: JPPD:   Pushdown from query block SEL$6D455ABB (#1) passed validity checks.
Join-Predicate push-down on query block SEL$6D455ABB (#1)
JPPD: Using search type: linear
JPPD: Considering join predicate push-down
JPPD: Starting iteration 1, state space = (2) : (0)
JPPD: Performing join predicate push-down (no transformation phase) from query block SEL$6D455ABB (#1) to query block SEL$2 (#2)
Пока это похоже на существующее ограничение CBO. Указанное поведение проверялось в 11.2.0.3 и 12.1.0.1.

event 10384

event 10384 level 16384: force parallel query runs as serial. How to Force that a Parallel Query Runs in Serial with the Parallel Execution Plan (Doc ID 1114405.1)
[oracle@oracle]$ oerr ora 10384
10384, 00000, "parallel dataflow scheduler tracing"
// *Cause:
// *Action:   set this event only under the supervision of Oracle development
// *Comment:  trace level is a bitfield (see kkrp.h)
Test case (run on 11.2.0.3):
doc
  create test data
#
create table t as select * from dba_objects;

doc
  set statistics_level=all and run parallel query
#

alter session set statistics_level=all;
select /*+ parallel(t)*/count(*) from t;
select * from table(dbms_xplan.display_cursor( format=> 'allstats all'));

doc
  purge cursor
#

col address    new_v address
col hash_value new_v hash_value
select address, hash_value from v$sql where sql_id='apmsk02t1z90x';
exec sys.dbms_shared_pool.purge( '&address.,&hash_value.', 'c')

doc
  set event 10384 level 16384, _px_trace=all and run query
#

alter session set events '10384 level 16384';
alter session set "_px_trace"=all;

select /*+ parallel(t)*/count(*) from t;
select * from table(dbms_xplan.display_cursor( format=> 'allstats all'));
alter session set events '10384 off';
Row source execution statistics of first execution. Default degree 16, starts for 5th line is 16.
-----------------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation              | Name     | Starts | E-Rows | Cost (%CPU)| E-Time   |    TQ  |IN-OUT| PQ Distrib | A-Rows |   A-Time   | Buffers | Reads  |
-----------------------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT       |          |      1 |        |     4 (100)|          |        |      |            |      1 |00:00:00.59 |       5 |      0 |
|   1 |  SORT AGGREGATE        |          |      1 |      1 |            |          |        |      |            |      1 |00:00:00.59 |       5 |      0 |
|   2 |   PX COORDINATOR       |          |      1 |        |            |          |        |      |            |     16 |00:00:00.59 |       5 |      0 |
|   3 |    PX SEND QC (RANDOM) | :TQ10000 |      0 |      1 |            |          |  Q1,00 | P->S | QC (RAND)  |      0 |00:00:00.01 |       0 |      0 |
|   4 |     SORT AGGREGATE     |          |     16 |      1 |            |          |  Q1,00 | PCWP |            |     16 |00:00:01.16 |     567 |    189 |
|   5 |      PX BLOCK ITERATOR |          |     16 |  12736 |     4   (0)| 00:00:01 |  Q1,00 | PCWC |            |  14275 |00:00:01.16 |     567 |    189 |
|*  6 |       TABLE ACCESS FULL| T        |    189 |  12736 |     4   (0)| 00:00:01 |  Q1,00 | PCWP |            |  14275 |00:00:01.14 |     567 |    189 |
-----------------------------------------------------------------------------------------------------------------------------------------------------------
Row source execution statistics of second execution. Starts for 5th line is 1. Parallel plan executed serially.
-----------------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation              | Name     | Starts | E-Rows | Cost (%CPU)| E-Time   |    TQ  |IN-OUT| PQ Distrib | A-Rows |   A-Time   | Buffers | Reads  |
-----------------------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT       |          |      1 |        |     4 (100)|          |        |      |            |      1 |00:00:00.02 |     194 |     63 |
|   1 |  SORT AGGREGATE        |          |      1 |      1 |            |          |        |      |            |      1 |00:00:00.02 |     194 |     63 |
|   2 |   PX COORDINATOR       |          |      1 |        |            |          |        |      |            |      1 |00:00:00.02 |     194 |     63 |
|   3 |    PX SEND QC (RANDOM) | :TQ10000 |      1 |      1 |            |          |  Q1,00 | P->S | QC (RAND)  |      1 |00:00:00.02 |     194 |     63 |
|   4 |     SORT AGGREGATE     |          |      1 |      1 |            |          |  Q1,00 | PCWP |            |      1 |00:00:00.02 |     194 |     63 |
|   5 |      PX BLOCK ITERATOR |          |      1 |  12736 |     4   (0)| 00:00:01 |  Q1,00 | PCWC |            |  14275 |00:00:00.02 |     194 |     63 |
|*  6 |       TABLE ACCESS FULL| T        |      1 |  12736 |     4   (0)| 00:00:01 |  Q1,00 | PCWP |            |  14275 |00:00:00.02 |     194 |     63 |
-----------------------------------------------------------------------------------------------------------------------------------------------------------
Trace file with event 10384 set contains a line:
Parallelism disabled at runtime because forced serial by event 10384

вторник, 22 июля 2014 г.

event 10309

[oracle@oracle ~]$ oerr ora 10309
10309, 00000, "Trigger Debug event"
// *Document: NO
// *Cause:
// *Action:
// *Comment: This event replaces the earlier event number 10250
//           which had multiple definitions
Test case (run on 11.2.0.3):
drop user tc cascade;
grant connect to tc identified by tc;
grant alter session to tc;
grant create table to tc;
grant create trigger to tc;
alter user tc quota 100M on users;

conn tc/tc
create table t(x int);
create trigger t_bi
  before insert on t
declare
begin
  null;
end;
/
create trigger t_bir 
  before insert on t
  for each row
declare
begin
  null;
end;
/
create trigger t_air 
  after insert on t
  for each row
declare
begin
  null;
end;
/
alter session set events '10309';
insert into t values (0);
select value from v$diag_info where name='Default Trace File';
Trace file:
*** 2014-07-21 09:42:05.051
*** SESSION ID:(76.9819) 2014-07-21 09:42:05.051
*** CLIENT ID:() 2014-07-21 09:42:05.051
*** SERVICE NAME:(SYS$USERS) 2014-07-21 09:42:05.051
*** MODULE NAME:(SQL*Plus) 2014-07-21 09:42:05.051
*** ACTION NAME:() 2014-07-21 09:42:05.051

--------Dumping Sorted Master Trigger List --------
Trigger Owner : TC
Trigger Name : T_AIR
Trigger Owner : TC
Trigger Name : T_BIR
Trigger Owner : TC
Trigger Name : T_BI
--------Dumping Trigger Sublists --------
 trigger sublist 0 :
Trigger Owner : TC
Trigger Name : T_BI
 trigger sublist 1 :
Trigger Owner : TC
Trigger Name : T_BIR
 trigger sublist 2 :
 trigger sublist 3 :
Trigger Owner : TC
Trigger Name : T_AIR
 trigger sublist 4 :
--------Dumping Sorted Master Trigger List --------
Trigger Owner : TC
Trigger Name : T_AIR
Trigger Owner : TC
Trigger Name : T_BIR
Trigger Owner : TC
Trigger Name : T_BI
--------Dumping Trigger Sublists --------
 trigger sublist 0 :
Trigger Owner : TC
Trigger Name : T_BI
 trigger sublist 1 :
Trigger Owner : TC
Trigger Name : T_BIR
 trigger sublist 2 :
 trigger sublist 3 :
Trigger Owner : TC
Trigger Name : T_AIR
 trigger sublist 4 :

*** 2014-07-21 09:42:05.073
Firing Insert Before Table Trigger. Name: T_BI Owner TC
Firing Insert Before Row Trigger. Name: T_BIR Owner TC
Firing Insert After Row Trigger. Name: T_AIR Owner TC

понедельник, 21 июля 2014 г.

Bug 15931756 - ORA-4031 Queries against SYS_FBA_TRACKEDTABLES not shared (do not use binds)

В одной из промышленных БД версии 11.2.0.3.7 обнаружил большое количество системных SQL, не использующих литералы.
/*
Find queries that are not using bind variables
*/
select s.*, 
      (select sql_text from v$sqlarea where force_matching_signature=sig and rownum=1) sql_text
  from (
       select inst_id, to_char(force_matching_signature) sig,
              count(exact_matching_signature) cnt
         from (
              select inst_id, force_matching_signature, exact_matching_signature
                from gv$sql
               group by inst_id, force_matching_signature, exact_matching_signature
              )
        group by inst_id, force_matching_signature
       having count(exact_matching_signature) > 1
        order by cnt desc
       ) s
 where rownum <= 10
В выводе оказалось множество запросов вида:
select FLAGS from SYS_FBA_TRACKEDTABLES where OBJ# = 1865226
select count(FA#) from SYS_FBA_TRACKEDTABLES where OBJ# = 1864581 and bitand(FLAGS, 128)=0
С кол-вом подобных курсоров в кол-ве 501 и 399 соответственно.
SQL> select sql_text from v$sql where force_matching_signature=15893216616221909352 and rownum<=10;
SQL_TEXT
---------------------------------------------------------------------------------
select FLAGS from SYS_FBA_TRACKEDTABLES where OBJ# = 1865226
select FLAGS from SYS_FBA_TRACKEDTABLES where OBJ# = 1865182
select FLAGS from SYS_FBA_TRACKEDTABLES where OBJ# = 1865129
select FLAGS from SYS_FBA_TRACKEDTABLES where OBJ# = 1864747
select FLAGS from SYS_FBA_TRACKEDTABLES where OBJ# = 1864989
select FLAGS from SYS_FBA_TRACKEDTABLES where OBJ# = 1865069
select FLAGS from SYS_FBA_TRACKEDTABLES where OBJ# = 1864718
select FLAGS from SYS_FBA_TRACKEDTABLES where OBJ# = 1864786
select FLAGS from SYS_FBA_TRACKEDTABLES where OBJ# = 1864815
select FLAGS from SYS_FBA_TRACKEDTABLES where OBJ# = 1864679
Поиск на MOS по SYS_FBA_TRACKEDTABLES тут же выдает, что имеет место быть баг: Bug 15931756 - ORA-4031 / Queries against SYS_FBA_TRACKEDTABLES not shared (do not use binds) (Doc ID 15931756.8)