Failed Logins can cause row cache lock on dc_users

One “feature” to be aware of in old-fashioned Oracle 11g – took me a while to figure it out, so just in case anyone else gets hit by it…

I changed the password of a schema in a test database to stop anything connecting whilst that schema was being logically refreshed.

Following this change, this environment started crawling but, despite being heavily used, no-one was complaining apart from me.

I couldn’t connect, just seemed to be “hanging” and for any existing connections certain statements were very slow.

I could see lots of row cache locks, the p1 of which decoded to dc_users.

Spent a while trying to figure it out, and eventually asked for a couple of second opinions on at the environment – they had no problems connecting, could see the row cache locks and eventually bounced the database.

Nothing got any better.

Another strange thing was that when looking at the sessions via ASH, they were all SYS sessions but with a session module that could not have been SYS – i.e application connections, etc.

So, that pointed at recursive SQL.

select count(*) over (partition by sample_time) sess_cnt
,      (select username from dba_users u where u.user_id = h.user_id) u
,      sample_time, session_state, session_id, sql_id
,      module, event, p1, blocking_session
from   dba_hist_active_sess_history h
where  event = 'row cache lock'
order by sample_time desc;
SESS_CNT U     SAMPLE_TIME                   SESSION_STATE SESSION_ID MODULE                  EVENT             P1 BLOCKING_SESSION
-------- ----- ----------------------------- ------------- ---------- ----------------------- ----------------- -- ----------------
      19 SYS   11-JUL-13 10.19.15.935000000  WAITING             1828 sqlplus@xx (TNS V1-V3)  row cache lock     7                  
      19 SYS   11-JUL-13 10.19.15.935000000  WAITING             2172 JDBC Thin Client        row cache lock     7             1898 
      19 SYS   11-JUL-13 10.19.15.935000000  WAITING             1837 JDBC Thin Client        row cache lock     7             2144 
      19 SYS   11-JUL-13 10.19.15.935000000  WAITING             1848 JDBC Thin Client        row cache lock     7             1898 
      19 SYS   11-JUL-13 10.19.15.935000000  WAITING             1880 sqlplus@xx (TNS V1-V3)  row cache lock     7             2144 
      19 SYS   11-JUL-13 10.19.15.935000000  WAITING             1886 JDBC Thin Client        row cache lock     7             1909 
      19 SYS   11-JUL-13 10.19.15.935000000  WAITING             2012 JDBC Thin Client        row cache lock     7             2144 
      19 SYS   11-JUL-13 10.19.15.935000000  WAITING             2026 sqlplus@xx (TNS V1-V3)  row cache lock     7             1898 
      19 SYS   11-JUL-13 10.19.15.935000000  WAITING             2031 JDBC Thin Client        row cache lock     7             1898 
      19 SYS   11-JUL-13 10.19.15.935000000  WAITING             2041 JDBC Thin Client        row cache lock     7             2144 
      19 SYS   11-JUL-13 10.19.15.935000000  WAITING             2058 sqlplus@xx (TNS V1-V3)  row cache lock     7             1898 
      19 SYS   11-JUL-13 10.19.15.935000000  WAITING             2063 JDBC Thin Client        row cache lock     7             2144 
      19 SYS   11-JUL-13 10.19.15.935000000  WAITING             2064 SQL Developer           row cache lock     7             2144 
      19 SYS   11-JUL-13 10.19.15.935000000  WAITING             2073 sqlplus@xx (TNS V1-V3)  row cache lock     7             1898 
      19 SYS   11-JUL-13 10.19.15.935000000  WAITING             2084 sqlplus@xx (TNS V1-V3)  row cache lock     7                  
      19 SYS   11-JUL-13 10.19.15.935000000  WAITING             2105 sqlplus@xx (TNS V1-V3)  row cache lock     7             1898 
      19 SYS   11-JUL-13 10.19.15.935000000  WAITING             2123 sqlplus@xx (TNS V1-V3)  row cache lock     7             1898 
      19 SYS   11-JUL-13 10.19.15.935000000  WAITING             2144 JDBC Thin Client        row cache lock     7             2041 
      19 SYS   11-JUL-13 10.19.15.935000000  WAITING             1832 sqlplus@xx (TNS V1-V3)  row cache lock     7             2144 

 19 rows selected 
select trunc(sample_time), count(*), min(sample_time), max(sample_time)
from   dba_hist_active_Sess_history
where  event = 'row cache lock'
group by trunc(sample_time)
order by trunc(sample_time);
TRUNC(SAMPLE_TIME) COUNT(*) MIN(SAMPLE_TIME)              MAX(SAMPLE_TIME)            
------------------ -------- ----------------------------- -----------------------------
02-JUL-13                10 02-JUL-13 04.08.48.955000000  02-JUL-13 16.12.30.128000000  
03-JUL-13                 2 03-JUL-13 11.42.30.367000000  03-JUL-13 22.02.38.886000000  
04-JUL-13                 6 04-JUL-13 04.10.25.568000000  04-JUL-13 22.02.52.536000000  
05-JUL-13                16 05-JUL-13 04.09.00.444000000  05-JUL-13 22.01.13.067000000  
06-JUL-13                 2 06-JUL-13 01.06.31.261000000  06-JUL-13 14.07.15.208000000  
08-JUL-13                26 08-JUL-13 03.10.53.909000000  08-JUL-13 22.00.45.416000000  
09-JUL-13                19 09-JUL-13 04.06.55.191000000  09-JUL-13 20.23.16.801000000  
10-JUL-13             48293 10-JUL-13 04.00.41.732000000  10-JUL-13 19.00.04.750000000  
11-JUL-13              5412 11-JUL-13 09.20.40.833000000  11-JUL-13 10.41.49.610000000  

 9 rows selected 

Eventually the penny dropped …

See bug 7715339 – Logon failures causes “row cache lock” waits – Allow disable of logon delay [ID 7715339.8]

In 11g there is an intentional delay between allowing failed logon
attempts to retry. For some specific application types this can cause
a problem as the row cache entry is locked for the duration of the
delay . This can lead to excessive row cache lock waits for DC_USERS
for specific users / schemas.

After 3 successive failures a sleep delay is introduced starting
at 3 seconds and extending to 10 seconds max. During each delay
the user X row cache lock is held in exclusive mode preventing
any concurrent logon attempt as user X (and preventing any
other operation which would need the row cache lock for user X).

That explains a) the problem and b) why the impact was limited.

CPU_time much higher than elapsed_time

Of course, one of the first places you should go is Oracle Support, but if you, like me, put off doing that and scratch your head for a while wondering why ELAPSED_TIME in V$SQL might be significantly lower than CPU_TIME when there are no obvious other explanations, then note these two bugs in 11.1.0.7:

BUG 7168259 – Millisecond elapsed_time shows as 0 : Elapsed_time for SQL statements which execute in under one millisecond can show up as 0

BUG 7561762 – Elapsed_time is under-reported : Elapsed_time can be 0 or significantly less than V$SQL.CPU_TIME if there is significant idle wait class time

Modelling a “simple” ITL problem

Today I have been looking at an application problem.

Last night important client processing missed its SLA with the application reporting ORA-02049: timeout: distributed timeout waiting for lock.

This post isn’t about the distributed lock timing out.

But consider the evidence that further investigation into these distributed locks threw up.

  1. The parameter distributed_lock_timeout is set to the default of 60 (seconds) – this means that any distributed transaction that waits for an enqueue for 60 seconds will be picked off by a sniper, similar to the standard deadlock detection after 3 seconds.
  2. The 1-in-10 second ASH samples in DBA_HIST_ACTIVE_SESS_HISTORY show clear waits on “enq: TX – allocate ITL entry”
  3. These same ASH samples show one particular sql id as being involved in the ITL waits.
  4. This particular sql id is a DELETE on a single table, no triggers, no on delete cascade referential integrity.

Sounds easy right?

But…

  1. V$SEGMENT_STATISTICS and DBA_HIST_SEG_STAT show 0 ITL waits for the segment/s related to the DELETE sql id above.
  2. In the ASH data, for the event “enq: TX – allocate ITL entry”, the CURRENT_OBJ# column indicates a variety of objects that might show ITL waits under concurrent DML but, again, all unrelated to the sql id identified by ASH.

So…

Time for some theories:

  1. ASH could be misleading us about the sql ids and/or
  2. ASH could be misleading about current_obj# and/or
  3. If our enqueue times out because of the distributed lock timeout, then perhaps the ITL wait is not recorded – i.e. segment stats are misleading.

Theories about ASH being misleading under certain circumstances are incredibly convoluted to test but, as far as I am concerned, even up to the latest 11gR2 this is a known known. There are certain values that are not cleared out or not recorded properly or disappear under certain conditions.

But perhaps we can test theory 3 relatively easily?

I like recycling – I’m going to reuse Randolf Geist’s ITL test case here.

SQL> get itl_case.sql
  1  create table t1 (c1 varchar2(1336)) pctfree 10;
  2  insert into t1 values ('a');
  3  insert into t1 values ('b');
  4  insert into t1 values ('c');
  5  insert into t1 values ('d');
  6  insert into t1 values ('e');
  7  insert into t1 values ('f');
  8  commit;
  9  update t1 set c1 = rpad(c1, 1335, c1) where length(c1) = 1;
 10* commit;
 11  .
SQL> @itl_case

Table created.
1 row created.
1 row created.
1 row created.
1 row created.
1 row created.
1 row created.
Commit complete.
6 rows updated.
Commit complete.

SQL>

Now I’m going to delete some rows across three sessions.
The first two session simple uncommitted deletes. The third will do a select over a db link in order to start the distributed transaction followed by the same simple delete.

First session – delete some rows and leave uncommitted so the ITL cannot be cleared:

SQL_SESS1>select distinct sid from v$mystat;

       SID
----------
      2056

SQL_SESS1>delete from t1 where c1 like 'a%';

1 row deleted.

SQL_SESS1>

Second session – delete some rows and leave uncommitted so the ITL cannot be cleared:

SQL_SESS2>select distinct sid from v$mystat;

       SID
----------
      2126

1 row selected.

SQL_SESS2>select to_char(sysdate,'DD-MON-YYYY HH24:MI') from dual;

TO_CHAR(SYSDATE,'
-----------------
01-NOV-2012 23:32

1 row selected.

SQL_SESS2>delete from t1 where c1 like 'b%';

1 row deleted.

SQL_SESS2>

Finally – third session – try to delete some rows within a distributed transaction:

SQL_SESS3>select distinct sid from v$mystat;

       SID
----------
      1884

1 row selected.

SQL_SESS3>select 1 from dual@mydba;

         1
----------
         1

1 row selected.

SQL_SESS3>delete from t1 where c1 like 'c%';
delete from t1 where c1 like 'c%'
*
ERROR at line 1:
ORA-02049: timeout: distributed transaction waiting for lock


SQL_SESS3>

Right, so what does ASH tell us about what happened?

SQL_SESS2>l
  1  select to_char(sample_time,'DD-MON-YYYY HH24:MI:SS'), sql_id, event, blocking_session, current_obj#
  2  from   v$active_Session_history
  3  where  event = 'enq: TX - allocate ITL entry'
  4  and    sample_time >= to_date('01-NOV-2012 23:32','DD-MON-YYYY HH24:MI')
  5* order  by sample_time desc
SQL_SESS2>/

TO_CHAR(SAMPLE_TIME, SQL_ID        EVENT                          BLOCKING_SESSION CURRENT_OBJ#
-------------------- ------------- ------------------------------ ---------------- ------------
01-NOV-2012 23:35:14 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:35:13 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:35:12 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:35:11 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:35:10 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:35:09 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:35:08 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:35:07 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:35:06 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:35:05 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:35:04 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:35:03 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:35:02 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:35:01 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:35:00 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:59 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:58 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:57 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:56 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:55 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:54 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:53 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:52 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:51 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:50 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:49 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:48 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:47 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:46 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:45 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:44 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:43 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:42 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:41 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:40 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:39 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:38 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:37 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:36 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:35 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:34 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:33 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:32 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:31 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:30 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:29 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:28 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:27 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:26 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:25 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:24 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:23 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:22 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:21 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:20 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:19 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:18 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:17 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:16 430xqxrrucgc5 enq: TX - allocate ITL entry               2126           -1
01-NOV-2012 23:34:15 430xqxrrucgc5 enq: TX - allocate ITL entry               2056           -1
01-NOV-2012 23:34:14 430xqxrrucgc5 enq: TX - allocate ITL entry               2056           -1
01-NOV-2012 23:34:13 430xqxrrucgc5 enq: TX - allocate ITL entry               2056           -1
01-NOV-2012 23:34:12 430xqxrrucgc5 enq: TX - allocate ITL entry               2056           -1
01-NOV-2012 23:34:11 430xqxrrucgc5 enq: TX - allocate ITL entry               2056           -1

71 rows selected.

Elapsed: 00:00:00.04
SQL_SESS2>

So, we are reporting wait event “enq: TX – allocate ITL entry” which was the aim.

And look at column current_obj# – seems perhaps that it is not set properly for this wait event (even though my rows in my real world example were not -1)

Sql id 430xqxrrucgc5 is my delete statement so that is bang on the money.

Finally, what do segment statistics say about ITL waits for this object t1?

SQL_SESS3>l
  1  select statistic_name, value
  2  from   v$segment_statistics
  3  where  object_name = 'T1'
  4* and    statistic_name = 'ITL waits'
SQL_SESS3>/

STATISTIC_NAME                                                        VALUE
---------------------------------------------------------------- ----------
ITL waits                                                                 0

1 row selected.

SQL_SESS3>

Because the statement was sniped by the distributed transaction timeout, the segment ITL statistics are not incremented and so these (and AWRs snaps thereof) miss the significance.

A good point made by Coskan is that I did not include the blocking session information in my ASH output.

Simply this is because it made the output too wide.

One of the sessions is reported as blocker but in reality there may be many blockers – it’s as many as there are ITL slots.

Also, depending on how many sessions are waiting, you may find that your blocked statement is unlucky and gets superceded by other sessions who get the ITL just through good timing of when they tried to get the enqueue. This is what was happening in my particular situation where an unlucky session was blocked for 1 minute – up to the distributed lock timeout – by a variety of blockers who at other times in that minute were busy doing other stuff not all waiting on this enqueue.

Gotcha: Application Contexts

This is one of those feature behaviours which isn’t surprising, but you probably wouldn’t think about it unless you saw it.

The flop:

I make heavy use of application contexts in flexible, variable input, dynamically-built queries (one of the options mentioned in this asktom thread for example).

(In the latest edition of Oracle Magazine, Tom explains why this is not an approach he would recommend any more. I don’t necessarily agree but more of that another time perhaps)

The Turn:

My Query Builder – a set of code which I’ve always intended to make publicly available but have yet to do so – uses a context with single namespace and typically reuses attribute names between queries – e.g. a product id populated from an on-screen product selector will typically populate a context attribute called PRODUCT_ID.

And a Query Builder implementation will typically reset any context attributes(DBMS_SESSION.CLEAR_ALL_CONTEXT) at the start to clear any parameters from a previous query.

In one of the more complex scenarios, a controller proc constructs three different queries, based on the input parameters supplied, in order to return three resultsets to populate three different parts of a GUI. A bit like this dummy code:

CREATE OR REPLACE PROCEDURE p_get_matching_data (
  i_parameters             IN  some_array_type
  o_cursor1                 OUT SYS_REFCURSOR,
  o_cursor2                 OUT SYS_REFCURSOR,
  o_cursor3                 OUT SYS_REFCURSOR
)
AS
   l_query1 LONG;
   l_query2 LONG;
   l_query3 LONG;
BEGIN
   l_query1 := my_query_builder_pkg.build_query1(i_parameters);
   OPEN o_cursor1 FOR l_query1;
   l_query2 := my_query_builder_pkg.build_query2(i_parameters);   
   OPEN o_cursor2 FOR l_query2;
   l_query3 := my_query_builder_pkg.build_query3(i_parameters);
   OPEN o_cursor3 FOR l_query3;
END;

The River:

The problem with SYS_CONTEXT is that it is not bound into the query like a bind variable, nor is it subject to the same read consistency mechanism as block data.

Witness:

DOMINIC@11gR1>VAR r REFCURSOR
DOMINIC@11gR1>CREATE CONTEXT demo_ctx USING context_demo_pkg;

Context created.

Elapsed: 00:00:00.00
DOMINIC@11gR1>CREATE OR REPLACE PACKAGE context_demo_pkg
  2  AS
  3    --
  4    PROCEDURE p_set_context (
  5      i_attribute                IN     VARCHAR2,
  6      i_value                    IN     VARCHAR2
  7    );
  8    --
  9    PROCEDURE p_unset_context (
 10      i_attribute                IN     VARCHAR2
 11    );
 12    --
 13  END;
 14  /

Package created.

Elapsed: 00:00:00.00
DOMINIC@11gR1>CREATE OR REPLACE PACKAGE BODY context_demo_pkg
  2  AS
  3    --
  4    k_namespace CONSTANT VARCHAR2(24) := 'DEMO_CTX';
  5    --
  6    PROCEDURE p_set_context (
  7      i_attribute                IN     VARCHAR2,
  8      i_value                    IN     VARCHAR2
  9    )
 10    AS
 11    BEGIN
 12       --
 13       DBMS_SESSION.SET_CONTEXT
 14       (namespace => k_namespace,
 15        attribute => i_attribute,
 16        value     => i_value);
 17       --
 18    END p_set_context;
 19    --
 20    PROCEDURE p_unset_context (
 21      i_attribute                IN     VARCHAR2
 22    )
 23    AS
 24    BEGIN
 25       --
 26       DBMS_SESSION.CLEAR_CONTEXT
 27       (namespace => k_namespace,
 28        attribute => i_attribute);
 29       --
 30    END p_unset_context;
 31    --
 32  END;
 33  /

Package body created.

Elapsed: 00:00:00.00
DOMINIC@11gR1>

Now to demonstrate the different behaviour.

The bind variable:

DOMINIC@11gR1>DECLARE
  2   l_value  varchar2(24) := 'My Test Bind';
  3  BEGIN
  4    open :r for select l_value from dual;
  5    l_value := null;
  6  END;
  7  /

PL/SQL procedure successfully completed.

:B1
--------------------------------
My Test Bind

Elapsed: 00:00:00.00
DOMINIC@11gR1>

No surprises there.
Now the illustration of read consistency:

DOMINIC@11gR1>CREATE TABLE test_data
  2  (col1 VARCHAR2(1));

Table created.

Elapsed: 00:00:01.02
DOMINIC@11gR1>
DOMINIC@11gR1>INSERT
  2  INTO   test_data 
  3  VALUES ('A');

1 row created.

Elapsed: 00:00:00.00
DOMINIC@11gR1>BEGIN
  2     OPEN :r FOR SELECT * FROM test_data;
  3     DELETE FROM test_data;
  4     COMMIT;
  5  END;
  6  /

PL/SQL procedure successfully completed.

C
-
A

Elapsed: 00:00:00.00
DOMINIC@11gR1>

Again, no surprises. Read consistency around cursor opening/fetching as you might expect.
Next, the application context.

Firstly, just to prove that it works:

DOMINIC@11gR1>BEGIN
  2     context_demo_pkg.p_set_context('VALUE1','My Test Bind');
  3     OPEN :r FOR SELECT SYS_CONTEXT('DEMO_CTX','VALUE1') FROM dual;
  4  END;
  5  /

PL/SQL procedure successfully completed.

SYS_CONTEXT('DEMO_CTX','VALUE1')
-------------------------------------
My Test Bind

Elapsed: 00:00:00.00
DOMINIC@11gR1>

But if we reset it before we fetch from the cursor:

DOMINIC@11gR1>BEGIN
  2     context_demo_pkg.p_set_context('VALUE1','My Test Bind');
  3     OPEN :r FOR SELECT SYS_CONTEXT('DEMO_CTX','VALUE1') FROM dual;
  4     context_demo_pkg.p_unset_context('VALUE1');
  5  END;
  6  /

PL/SQL procedure successfully completed.


SYS_CONTEXT('DEMO_CTX','VALUE1')
---------------------------------------

Elapsed: 00:00:00.00
DOMINIC@11gR1>

So, once you see it, not entirely unsurprising but maybe not something that you’d considered before ( I hadn’t ). Behaviour neither like a bind nor read consistency like block data.

Adventures with VPD I: Result Cache

Oh, the challenges of implementing VPD on a mature system!

Like partitioning and other major features, implementing VPD on a “mature”* database that has been “evolving”* over many years can be nowhere near as simple as designing such a solution from scratch. (* “Mature” databases have not necessarily “evolved” in a way that you might recommend. Best practice might not apply.)

Anyway, I’ve been intending to write a case study of my current VPD implementation, dealing with some detail of the buy versus build decision of VPD versus OLS and the subsequent challenges and incompatibilities with various features. As usual, that article awaits but I wanted to kick off a mini-series on the various difficulties experienced (and this series might then help the coming together of a single article on the whole experience).

Challenge I
The challenge illustrated here is VPD + Result Cache.

Spoiler: For those who don’t want to read the whole article (it’s a bit long and the formatting which doesn’t help), the two work together but beware the subtle differences in behaviour between the SQL and PL/SQL Result Cache – read the documentation for each.

Quick Background
First a bit of background information which may help put these snippets of info into some sort of context.

  • As mentioned, this is a database that has been around for quite a few years now.
  • There has been a simple requirement to restrict access such that:
    • Users in the US can only see US data.
    • Users in the Rest of the World (ROW) cannot see US data.
  • VPD, OLS and a separate database were the options considered with VPD considered the only practical solution for one reason or another.

Demo
Let’s get into it.

Step 1: First up, script to create users for this demo:

  1. User to own table – APP_DATA
  2. User to own manage VPD security – SECURITY_MGR
  3. User to simulate app user with US visibility
  4. User to simulate app user with ROW visibility
-- Schema to hold some data
CREATE USER APP_DATA
IDENTIFIED BY password
DEFAULT TABLESPACE USERS
TEMPORARY TABLESPACE TEMP
QUOTA UNLIMITED ON USERS
ACCOUNT UNLOCK;

GRANT CREATE SESSION TO app_data;
GRANT CREATE TABLE TO app_data;
GRANT CREATE PROCEDURE TO app_data; 

-- Schema to manage security policies
CREATE USER SECURITY_MGR
IDENTIFIED BY password
DEFAULT TABLESPACE USERS
TEMPORARY TABLESPACE TEMP
QUOTA UNLIMITED ON USERS
ACCOUNT UNLOCK;

GRANT EXEMPT ACCESS POLICY TO security_mgr;
GRANT CREATE SESSION TO security_mgr;
GRANT CREATE TABLE TO security_mgr;
GRANT CREATE ANY CONTEXT TO security_mgr;
GRANT CREATE TRIGGER TO security_mgr;
GRANT ADMINISTER DATABASE TRIGGER TO security_mgr;
GRANT SELECT ANY TABLE TO security_mgr;
GRANT ALTER ANY TABLE TO security_mgr;
GRANT UPDATE ANY TABLE TO security_mgr;
GRANT EXECUTE ON DBMS_RLS TO security_mgr;
GRANT CREATE ANY TRIGGER TO security_mgr;
GRANT ADMINISTER DATABASE TRIGGER TO security_mgr;

-- User to see only US data
CREATE USER APP_USER_US
IDENTIFIED BY password
DEFAULT TABLESPACE USERS
TEMPORARY TABLESPACE TEMP
QUOTA UNLIMITED ON USERS
ACCOUNT UNLOCK;

GRANT CREATE SESSION TO app_user_us;

-- User to see only non-US data
CREATE USER APP_USER_ROW
IDENTIFIED BY password
DEFAULT TABLESPACE USERS
TEMPORARY TABLESPACE TEMP
QUOTA UNLIMITED ON USERS
ACCOUNT UNLOCK;

GRANT CREATE SESSION TO app_user_row;

Step 2: Next up, script to create table and data for this demo. It’s hardly imaginative nor a real world example…

conn app_data/password@dom11g

DROP TABLE cars;

CREATE TABLE cars
(id              NUMBER       NOT NULL
,make            VARCHAR2(48) NOT NULL
,security_label  VARCHAR2(6)  NOT NULL
,CONSTRAINT pk_cars PRIMARY KEY (id));

INSERT INTO app_data.cars
VALUES (1,'Audi','ROW');

INSERT INTO app_data.cars
VALUES (2,'Buick','US');

INSERT INTO app_data.cars
VALUES (3,'BMW','ROW');

INSERT INTO app_data.cars
VALUES (4,'Chrysler','US');

INSERT INTO app_data.cars
VALUES (5,'Citroen','US');

INSERT INTO app_data.cars
VALUES (6,'Dodge','US');

COMMIT;

GRANT SELECT ON cars TO app_user_us, app_user_row;

Step 3: Create vpd policies including

  • Create application context
  • Create package to manage context
  • Create logon trigger to set contexts
  • Create policy function that will apply predicates to policied tables
  • Apply policy to table
conn security_mgr/password@dom11g

CREATE CONTEXT security_ctx USING security_pkg;

CREATE OR REPLACE PACKAGE security_pkg
AS
  --
  PROCEDURE p_initialise_user;
  --
END security_pkg;
/

CREATE OR REPLACE PACKAGE BODY security_pkg
AS
  k_namespace CONSTANT VARCHAR2(12) := 'SECURITY_CTX';
  --
  PROCEDURE p_set_context (
    i_attribute  IN     VARCHAR2,
    i_value      IN     VARCHAR2
  )
  AS
  BEGIN
     --
     dbms_session.set_context(k_namespace,i_attribute,i_value);
     --
  END p_set_context;
  --
  PROCEDURE p_set_us_context
  AS
  BEGIN
     --
     p_set_context('CAN_SEE_US','Y');
     --
  END p_set_us_context;
  --
  PROCEDURE p_set_row_context
  AS
  BEGIN
     --
     p_set_context('CAN_SEE_ROW','Y');
     --
  END p_set_row_context;
  --
  PROCEDURE p_initialise_user
  AS
  BEGIN
     --
     IF USER = 'APP_USER_US'
     THEN
         --
         p_set_us_context;
         --
     ELSIF USER = 'APP_USER_ROW'
     THEN
         --
         p_set_row_context;
         --
     ELSE
         --
         p_set_us_context;
         p_set_row_context;
         --
     END IF;
     --
  END p_initialise_user;
  --
END security_pkg;
/

CREATE OR REPLACE TRIGGER tri_logon_set_rls_security
AFTER LOGON ON DATABASE
BEGIN
   --
   security_pkg.p_initialise_user;
   --
END tri_logon_set_rls_security;
/

CREATE OR REPLACE FUNCTION f_security_policy (
  i_schema                     IN     VARCHAR2 DEFAULT NULL,
  i_object                     IN     VARCHAR2 DEFAULT NULL
)
RETURN VARCHAR2
AS
BEGIN
   --
   RETURN CASE WHEN SYS_CONTEXT('SECURITY_CTX','CAN_SEE_US')  = 'Y'
               AND  SYS_CONTEXT('SECURITY_CTX','CAN_SEE_ROW') = 'Y'
               THEN NULL
               WHEN SYS_CONTEXT('SECURITY_CTX','CAN_SEE_US')  = 'Y'
               THEN ' security_label  = ''US'' '
               WHEN SYS_CONTEXT('SECURITY_CTX','CAN_SEE_ROW') = 'Y'
               THEN ' security_label = ''ROW'' '
          END;
   --
END f_security_policy;
/

begin
  dbms_rls.add_policy
  (object_schema   => 'APP_DATA',
   object_name     => 'CARS',
   policy_name     => 'RLS_CARS',
   function_schema => 'SECURITY_MGR',
   policy_function => 'F_SECURITY_POLICY',
   policy_type     => SYS.DBMS_RLS.SHARED_CONTEXT_SENSITIVE,
   statement_types => 'SELECT');
end;
/

Step 4: Test the VPD policies.
Step 4a: Connecting as APP_USER_US, we should only be able to see data from APP_DATA.CARS which is labelled as US:

conn app_user_us/password@dom11g

app_user_us@dom11g>select * from app_data.cars;

 ID MAKE       SECUR
--- ---------- -----
  2 Buick      US
  4 Chrysler   US
  5 Citroen    US
  6 Dodge      US

Elapsed: 00:00:00.01

Step 4b: Connecting as APP_USER_ROW, we should only be able to see data from APP_DATA.CARS which is labelled as ROW:

conn app_user_row/password@dom11g

app_user_row@dom11g>select * from app_data.cars;

app_user_row@dom11g>select * from app_data.cars;

 ID MAKE       SECUR
--- ---------- -----
  1 Audi       ROW
  3 BMW        ROW

Elapsed: 00:00:00.00
app_user_row@dom11g>

Good stuff. Spotted the mistake? Last time I checked, Citroen was French – should be labelled ROW. I’ll leave it in and update it after we’ve done some result cache queries just to show that that all works.

Step 5: Let’s take a look at the SQL result cache using the result_cache hint.
Step 5a: We’ll go with APP_USER_US first.

conn app_user_us/password@dom11g

app_user_us@dom11g>set autotrace on
app_user_us@dom11g>select /*+ result_cache */ * from app_data.cars;

 ID MAKE       SECUR
--- ---------- -----
  2 Buick      US
  4 Chrysler   US
  5 Citroen    US
  6 Dodge      US

Elapsed: 00:00:00.02

Execution Plan
----------------------------------------------------------
   0      SELECT STATEMENT Optimizer=ALL_ROWS (Cost=5 Card=4 Bytes=176)
   1    0   RESULT CACHE OF '25tyax8u9ktwf2g61acmsb5apa'
   2    1     TABLE ACCESS (FULL) OF 'CARS' (TABLE) (Cost=5 Card=4 Bytes=176)

Statistics
----------------------------------------------------------
        121  recursive calls
          0  db block gets
         58  consistent gets
          0  physical reads
          0  redo size
        508  bytes sent via SQL*Net to client
        427  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          1  sorts (memory)
          0  sorts (disk)
          4  rows processed

app_user_us@dom11g>select /*+ result_cache */ * from app_data.cars;

 ID MAKE       SECUR
--- ---------- -----
  2 Buick      US
  4 Chrysler   US
  5 Citroen    US
  6 Dodge      US

Elapsed: 00:00:00.02

Execution Plan
----------------------------------------------------------
   0      SELECT STATEMENT Optimizer=ALL_ROWS (Cost=5 Card=4 Bytes=176)
   1    0   RESULT CACHE OF '25tyax8u9ktwf2g61acmsb5apa'
   2    1     TABLE ACCESS (FULL) OF 'CARS' (TABLE) (Cost=5 Card=4 Bytes=176)

Statistics
----------------------------------------------------------
          0  recursive calls
          0  db block gets
          0  consistent gets
          0  physical reads
          0  redo size
        508  bytes sent via SQL*Net to client
        427  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          4  rows processed

I’m happy enough that it’s coming from the cache the second time.

Step 5a: How about APP_USER_US?

conn app_user_row/password@dom11g

app_user_row@dom11g>set autotrace on
app_user_row@dom11g>select /*+ result_cache */ * from app_data.cars;

 ID MAKE       SECUR
--- ---------- -----
  1 Audi       ROW
  3 BMW        ROW

Elapsed: 00:00:00.02

Execution Plan
----------------------------------------------------------
   0      SELECT STATEMENT Optimizer=ALL_ROWS (Cost=5 Card=2 Bytes=88)
   1    0   RESULT CACHE OF 'g0ubwn87rvz5s15cj3089zgn3h'
   2    1     TABLE ACCESS (FULL) OF 'CARS' (TABLE) (Cost=5 Card=2 Bytes=88)

Statistics
----------------------------------------------------------
         89  recursive calls
          0  db block gets
         57  consistent gets
          0  physical reads
          0  redo size
        473  bytes sent via SQL*Net to client
        427  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          2  rows processed

app_user_row@dom11g>select /*+ result_cache */ * from app_data.cars;

 ID MAKE       SECUR
--- ---------- -----
  1 Audi       ROW
  3 BMW        ROW

Elapsed: 00:00:00.02

Execution Plan
----------------------------------------------------------
   0      SELECT STATEMENT Optimizer=ALL_ROWS (Cost=5 Card=2 Bytes=88)
   1    0   RESULT CACHE OF 'g0ubwn87rvz5s15cj3089zgn3h'
   2    1     TABLE ACCESS (FULL) OF 'CARS' (TABLE) (Cost=5 Card=2 Bytes=88)

Statistics
----------------------------------------------------------
          1  recursive calls
          0  db block gets
          0  consistent gets
          0  physical reads
          0  redo size
        473  bytes sent via SQL*Net to client
        427  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          2  rows processed

Step 6: Let’s update that Citroen row – double check what happens.

conn app_data/password@dom11g

app_data@dom11g>update cars set security_label = 'ROW' where id = 5;

1 row updated.

Elapsed: 00:00:00.00
app_data@dom11g>commit;

Commit complete.

Step 7: Back to the visibility users
Step 7a: APP_USER_US

app_user_us@dom11g>select /*+ result_cache */ * from app_data.cars;

 ID MAKE       SECUR
--- ---------- -----
  2 Buick      US
  4 Chrysler   US
  6 Dodge      US

Elapsed: 00:00:00.00
app_user_us@dom11g>

Step 7b: APP_USER_ROW

app_user_row@dom11g>select /*+ result_cache */ * from app_data.cars;

 ID MAKE       SECUR
--- ---------- -----
  1 Audi       ROW
  3 BMW        ROW
  5 Citroen    ROW

Elapsed: 00:00:00.00
app_user_row@dom11g>

Looking more accurate now.

SQL Query Result Cache
So, the SQL Result Cache apparently works fine with VPD.
Let’s review what the documentation says:


Cached results are parameterized with the parameter values if any of the following constructs are used in the query:

Bind variables.

The following SQL functions: dbtimezone, sessiontimezone, userenv/sys_context (with constant variables), uid, and user.

NLS parameters.

Parameterized cache results can be reused if the query is equivalent and the parameter values are the same.

So what of the PL/SQL Function Result Cache?

Step 8: Create a result cache function to demonstrate (this is an artificial and simplified function – it demos what I want to demo, it’s derived from a real-world implementation but I would advocate using the result cache for this purpose)

conn app_data/password@dom11g

CREATE OR REPLACE PACKAGE cars_pkg
AS
--
FUNCTION f_get_make (
i_id IN cars.id%TYPE
)
RETURN cars.make%TYPE;
--
END cars_pkg;
/

CREATE OR REPLACE PACKAGE BODY cars_pkg
AS
--
TYPE t_cars IS TABLE of cars%ROWTYPE INDEX BY PLS_INTEGER;
--
FUNCTION f_get_cars
RETURN t_cars
RESULT_CACHE
RELIES_ON (cars)
AS
--
l_cars t_cars;
l_tmp_cars t_cars;
i PLS_INTEGER;
--
BEGIN
--
SELECT *
BULK COLLECT INTO l_tmp_cars
FROM cars;
--
i := l_tmp_cars.FIRST;
--
WHILE (i IS NOT NULL)
LOOP
--
l_cars(l_tmp_cars(i).id).id := l_tmp_cars(i).id;
l_cars(l_tmp_cars(i).id).make := l_tmp_cars(i).make;
l_cars(l_tmp_cars(i).id).security_label := l_tmp_cars(i).security_label;
--
i := l_tmp_cars.NEXT(i);
--
END LOOP;

--
RETURN l_cars;
--
END f_get_cars;
--
FUNCTION f_get_make (
i_id IN cars.id%TYPE
)
RETURN cars.make%TYPE
AS
--
l_cars t_cars;
--
BEGIN
--
l_cars := f_get_cars;
RETURN l_cars(i_id).make;
--
EXCEPTION
WHEN no_data_found THEN
RETURN NULL;
END f_get_make;
--
END cars_pkg;
/

GRANT EXECUTE ON cars_pkg TO app_user_us, app_user_row;

Step 9: Let’s try it using this.
Step 9a: As APP_USER_US initially

app_user_us@dom11g>var v varchar2(48)
app_user_us@dom11g>set autoprint on
app_user_us@dom11g>select * from app_data.cars;

 ID MAKE       SECUR
--- ---------- -----
  2 Buick      US
  4 Chrysler   US
  6 Dodge      US

Elapsed: 00:00:00.01
app_user_us@dom11g>exec :v := app_data.cars_pkg.f_get_make(1);

PL/SQL procedure successfully completed.

V
---------------

Elapsed: 00:00:00.01
app_user_us@dom11g>exec :v := app_data.cars_pkg.f_get_make(2);

PL/SQL procedure successfully completed.

V
---------------
Buick

Elapsed: 00:00:00.01

As expected, APP_USER_US cannot see the Audi data, can see Buick. Perfect!
Step 9b: Let’s try APP_USER_ROW.

conn app_user_row/password@dom11g

app_user_row@dom11g>var v varchar2(48)
app_user_row@dom11g>set autoprint on
app_user_row@dom11g>select * from app_data.cars;

  ID MAKE       SECUR
---- ---------- -----
   1 Audi       ROW
   3 BMW        ROW
   5 Citroen    ROW

Elapsed: 00:00:00.00
app_user_row@dom11g>exec :v := app_data.cars_pkg.f_get_make(1);

PL/SQL procedure successfully completed.

V
----------

Elapsed: 00:00:00.01
app_user_row@dom11g>exec :v := app_data.cars_pkg.f_get_make(2);

PL/SQL procedure successfully completed.

V
----------
Buick

Elapsed: 00:00:00.01
app_user_row@dom11g>

Wrong! And just what I wanted to demo. By implementing a result function like this, I have bypassed my VPD and rendered results from this function unpredictable depending on who ran the results which were cached.

So, with the PL/SQL function RESULT_CACHE directive you have to be careful, not necessarily anymore so than certain other features but just something to be aware of.

Before I knew the solution, but after I had these results, what happened when I combined VPD with such a Result Cache mis-implementation was not a massive surprise, but I had expected that either an error message would be raised, similiar to Materialized Views or the MERGE statement (forward references to future articles on the challenges of combining VPD with those two), or perhaps that the RESULT_CACHE directive would be ignored.

However the behaviour is documented and the answer is very much documented in the PL/SQL Language Reference:

Making Result-Cached Functions Handle Session-Specific Settings

The PL/SQL function result-caching feature does not automatically handle dependence on session-specific application contexts. If you must cache the results of a function that depends on session-specific application contexts, you must pass the application context to the function as a parameter. You can give the parameter a default value, so that not every user must specify it.

The same advice applies to other session specific settings, e.g. NLS_DATE_FORMAT etc.

Step 10: Make safe the result_cache implementation of APP_DATA.CARS_PKG.

conn app_data/password@dom11g

CREATE OR REPLACE PACKAGE APP_DATA.cars_pkg
AS
  --
  FUNCTION f_get_make_safe (
    i_id          IN  cars.id%TYPE,
    i_can_see_us  IN  VARCHAR2 DEFAULT SYS_CONTEXT('SECURITY_CTX','CAN_SEE_US'),
    i_can_see_row IN  VARCHAR2 DEFAULT SYS_CONTEXT('SECURITY_CTX','CAN_SEE_ROW')
  )
  RETURN cars.make%TYPE;
  --
END cars_pkg;
/

CREATE OR REPLACE PACKAGE BODY APP_DATA.cars_pkg
AS
  --
  TYPE t_cars IS TABLE of cars%ROWTYPE INDEX BY PLS_INTEGER;
  --
  FUNCTION f_get_cars_safe (
    i_can_see_us  IN  VARCHAR2 DEFAULT SYS_CONTEXT('SECURITY_CTX','CAN_SEE_US'),
    i_can_see_row IN  VARCHAR2 DEFAULT SYS_CONTEXT('SECURITY_CTX','CAN_SEE_ROW')
  )
  RETURN t_cars
  RESULT_CACHE
  RELIES_ON (cars)
  AS
    --
    l_cars     t_cars;
    l_tmp_cars t_cars;
    i          PLS_INTEGER;
    --
  BEGIN
     --
     SELECT *
     BULK COLLECT INTO l_tmp_cars
     FROM   cars;
     --
     i := l_tmp_cars.FIRST;
     --
     WHILE (i IS NOT NULL)
     LOOP
         --
         l_cars(l_tmp_cars(i).id).id             := l_tmp_cars(i).id;
         l_cars(l_tmp_cars(i).id).make           := l_tmp_cars(i).make;
         l_cars(l_tmp_cars(i).id).security_label := l_tmp_cars(i).security_label;
         --
         i := l_tmp_cars.NEXT(i);
         --
     END LOOP;

     --
     RETURN l_cars;
     --
  END f_get_cars_safe;
  --
  FUNCTION f_get_make_safe (
    i_id          IN  cars.id%TYPE,
    i_can_see_us  IN  VARCHAR2 DEFAULT SYS_CONTEXT('SECURITY_CTX','CAN_SEE_US'),
    i_can_see_row IN  VARCHAR2 DEFAULT SYS_CONTEXT('SECURITY_CTX','CAN_SEE_ROW')
  )
  RETURN cars.make%TYPE
  AS
    --
    l_cars t_cars;
    --
  BEGIN
     --
     l_cars := f_get_cars_safe;
     RETURN l_cars(i_id).make;
     --
  EXCEPTION
       WHEN no_data_found THEN
            RETURN NULL;
  END f_get_make_safe;
  --
END cars_pkg;
/

Step 11: With this our previous function lookup should work as expected:
Step 11a: As APP_USER_US

conn app_user_us/password@dom11g

app_user_us@dom11g>var v varchar2(48)
app_user_us@dom11g>set autoprint on
app_user_us@dom11g>select * from app_data.cars;

  ID MAKE       SECUR
---- ---------- -----
   2 Buick      US
   4 Chrysler   US
   6 Dodge      US

Elapsed: 00:00:00.01
app_user_us@dom11g>exec :v := app_data.cars_pkg.f_get_make_safe(1);

PL/SQL procedure successfully completed.

V
----------

Elapsed: 00:00:00.01
app_user_us@dom11g>exec :v := app_data.cars_pkg.f_get_make_safe(2);

PL/SQL procedure successfully completed.

V
----------
Buick

Elapsed: 00:00:00.01

Step 11a: As APP_USER_ROW

conn app_user_row/password@dom11g

app_user_row@dom11g>var v varchar2(48)
app_user_row@dom11g>set autoprint on
app_user_row@dom11g>select * from app_data.cars;

  ID MAKE       SECUR
---- ---------- -----
   1 Audi       ROW
   3 BMW        ROW
   5 Citroen    ROW

Elapsed: 00:00:00.01
app_user_row@dom11g>exec :v := app_data.cars_pkg.f_get_make_safe(1);

PL/SQL procedure successfully completed.

V
----------
Audi

Elapsed: 00:00:00.01
app_user_row@dom11g>exec :v := app_data.cars_pkg.f_get_make_safe(2);

PL/SQL procedure successfully completed.

V
----------

Elapsed: 00:00:00.01
app_user_row@dom11g>

Problem fixed.

Moral
The moral of the story is simple in this case – RTFM.
This time everything I needed was there in the docs. I hadn’t picked up on it fully when I implemented the result cache procs when VPD wasn’t in the picture and I didn’t review the information up front when looking at the VPD solution.
Caveat Developer.

Documentation

11.1.0.7 Follow up

As a follow-up to Friday’s post about some local issues with the 11.1.0.7 patch, I’ve distilled an isolated piece of SQL to demonstrate the ORA-03113.

Demo test case looks like this:


DOM@11g>l
    WITH subq_goes_bang_data AS
         (SELECT 'CST1' database_name,'-6' ro_id,'\\xxxxx\uts_dev\SplitterToolSystemTestRO1' ros_path
          FROM   dual)
    ,    subq_db_name   AS
         (SELECT DECODE (INSTR (global_name, '.WORLD'),
                         0,global_name,
                         SUBSTR (global_name,1,INSTR (global_name,'.WORLD') - 1)
                        ) database_name
          FROM   global_name)
   ,    subq_goes_bang AS
       (
        SELECT rrc.ro_id,
               rrc.ros_path
        FROM   subq_goes_bang_data rrc
        WHERE rrc.database_name = (SELECT database_name FROM subq_db_name)
        UNION ALL
        SELECT rrc.ro_id,
               rrc.ros_path
        FROM   subq_goes_bang_data rrc
        WHERE  rrc.database_name = 'CST1'
        AND    NOT EXISTS(SELECT NULL
                          FROM subq_goes_bang_data rrc1
                          WHERE rrc1.database_name =(SELECT database_name FROM subq_db_name)
                          AND rrc1.ro_id = rrc.ro_id)
        AND    'CSP1' <>(SELECT database_name FROM subq_db_name)
   )
   SELECT  '<?xml version="1.0" encoding="UTF-16"?>'
           || XMLELEMENT ("LocalConfiguration",XMLFOREST (a.ros_path AS "RootFilePath"))
   FROM    subq_goes_bang a
  WHERE   a.ro_id = -6

DOM@11g>/
WITH subq_goes_bang_data AS
*
ERROR at line 1:
ORA-03113: end-of-file on communication channel


Elapsed: 00:00:00.05
DOM@11g>

Comment out the XML bits and bobs and just select the column – no problem.
Comment out the UNION ALL in subq_goes_bang – no problem.

Explain plan looks like this:


DOM@11g>explain plan for
  2  WITH subq_goes_bang_data AS
  3       (SELECT 'CST1' database_name,'-6' ro_id,'\\xxxxx\uts_dev\SplitterToolSystemTestRO1' ros_path 
  4        FROM   dual)
  5  ,    subq_db_name   AS
  6       (SELECT DECODE (INSTR (global_name, '.WORLD'),
  7                       0,global_name,
  8                       SUBSTR (global_name,1,INSTR (global_name,'.WORLD') - 1)
  9                      ) database_name
 10        FROM   global_name)
 11  ,    subq_goes_bang AS
 12      (
 13       SELECT rrc.ro_id,
 14              rrc.ros_path
 15       FROM   subq_goes_bang_data rrc
 16       WHERE rrc.database_name = (SELECT database_name FROM subq_db_name)
 17       UNION ALL
 18       SELECT rrc.ro_id,
 19              rrc.ros_path
 20       FROM   subq_goes_bang_data rrc
 21       WHERE  rrc.database_name = 'CST1'
 22       AND    NOT EXISTS(SELECT NULL
 23                         FROM subq_goes_bang_data rrc1
 24                         WHERE rrc1.database_name =(SELECT database_name FROM subq_db_name)
 25                         AND rrc1.ro_id = rrc.ro_id)
 26       AND    'CSP1' <> (SELECT database_name FROM subq_db_name)
 27  )
 28  SELECT  '<?xml version="1.0" encoding="UTF-16"?>'
 29          || XMLELEMENT ("LocalConfiguration",XMLFOREST (a.ros_path AS "RootFilePath"))
 30  FROM    subq_goes_bang a
 31  WHERE   a.ro_id = -6;

Explained.

Elapsed: 00:00:00.00
DOM@11g>
DOM@11g>select * from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
Plan hash value: 4143783385

----------------------------------------------------------------------------------------------------
| Id  | Operation                  | Name                        | Rows  | Bytes | Cost (%CPU)| Time     |
----------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT           |                             |     2 |    86 |    16   (7)| 00:00:01 |
|   1 |  TEMP TABLE TRANSFORMATION |                             |       |       |            |          |
|   2 |   LOAD AS SELECT           |                             |       |       |            |          |
|   3 |    INDEX FULL SCAN         | SYS_IOT_TOP_57625           |     1 |       |     1   (0)| 00:00:01 |
|   4 |   LOAD AS SELECT           |                             |       |       |            |          |
|*  5 |    TABLE ACCESS FULL       | PROPS$                      |     1 |    27 |     2   (0)| 00:00:01 |
|   6 |   VIEW                     |                             |     2 |    86 |    13   (8)| 00:00:01 |
|   7 |    UNION-ALL               |                             |       |       |            |          |
|*  8 |     VIEW                   |                             |     1 |    53 |     2   (0)| 00:00:01 |
|   9 |      TABLE ACCESS FULL     | SYS_TEMP_0FD9D6643_B0B39986 |     1 |    53 |     2   (0)| 00:00
|  10 |      VIEW                  |                             |     1 |  2002 |     2   (0)| 00:00:01 |
|  11 |       TABLE ACCESS FULL    | SYS_TEMP_0FD9D6644_B0B39986 |     1 |    27 |     2   (0)| 00:0
|* 12 |     FILTER                 |                             |       |       |            |          |
|* 13 |      HASH JOIN ANTI        |                             |     1 |    57 |     7  (15)| 00:00:01 |
|* 14 |       VIEW                 |                             |     1 |    53 |     2   (0)| 00:00:01 |
|  15 |        TABLE ACCESS FULL   | SYS_TEMP_0FD9D6643_B0B39986 |     1 |    53 |     2   (0)| 00:0
|  16 |       VIEW                 | VW_SQ_1                     |     1 |     4 |     4   (0)| 00:00:01 |
|* 17 |        VIEW                |                             |     1 |    10 |     2   (0)| 00:00:01 |
|  18 |         TABLE ACCESS FULL  | SYS_TEMP_0FD9D6643_B0B39986 |     1 |    53 |     2   (0)| 00:00:01 |
|  19 |         VIEW               |                             |     1 |  2002 |     2   (0)| 00:00:01 |
|  20 |          TABLE ACCESS FULL | SYS_TEMP_0FD9D6644_B0B39986 |     1 |    27 |     2   (0)| 00:00:01 |
|  21 |      VIEW                  |                             |     1 |  2002 |     2   (0)| 00:00:01 |
|  22 |       TABLE ACCESS FULL    | SYS_TEMP_0FD9D6644_B0B39986 |     1 |    27 |     2   (0)| 00:0
----------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   5 - filter("NAME"='GLOBAL_DB_NAME')
   8 - filter(TO_NUMBER("RRC"."RO_ID")=(-6) AND "RRC"."DATABASE_NAME"= (SELECT "DATABASE_NAME"
              FROM  (SELECT /*+ CACHE_TEMP_TABLE ("T1") */ "C0" "DATABASE_NAME" FROM
              "SYS"."SYS_TEMP_0FD9D6644_B0B39986" "T1") "SUBQ_DB_NAME"))
  12 - filter( (SELECT "DATABASE_NAME" FROM  (SELECT /*+ CACHE_TEMP_TABLE ("T1") */ "C0"
              "DATABASE_NAME" FROM "SYS"."SYS_TEMP_0FD9D6644_B0B39986" "T1") "SUBQ_DB_NAME")<>'CSP1')
  13 - access("ITEM_0"="RRC"."RO_ID")
  14 - filter("RRC"."DATABASE_NAME"='CST1' AND TO_NUMBER("RRC"."RO_ID")=(-6))
  17 - filter("RRC1"."DATABASE_NAME"= (SELECT "DATABASE_NAME" FROM  (SELECT /*+ CACHE_TEMP_TABLE
              ("T1") */ "C0" "DATABASE_NAME" FROM "SYS"."SYS_TEMP_0FD9D6644_B0B39986" "T1") "SUBQ_DB_NAME")

43 rows selected.

Elapsed: 00:00:00.01
DOM@11g>

So, to Oracle support with some trace files.

But I’d be interested if anyone else with an 11.1.0.7 environment can run the above statement.

Follow

Get every new post delivered to your Inbox.

Join 70 other followers