Doug's Oracle Blog

... and quite funny. I followed an incoming link through Statcounter and arrived here.

At the moment, the content is :-

SQL> startup mount
ORACLE instance started.

Total System Global Area 645922816 bytes 
Fixed Size 1250644 bytes 
Variable Size 184552108 bytes 
Database Buffers 457179136 bytes 
Redo Buffers 2940928 bytes 
Database mounted.
SQL> alter database open;
Database altered.

One of the problems in working with Parallel Execution is that you tend to work on it in bursts, usually when a data warehouse is running into problems, and then don't work on it for months. I'm in the middle of one of those bursts and there are a couple of related issues that I wanted to cover. (Postscript - this turned out to be a much longer blog than I planned - both in number of words and time spent!)

Limiting Logical Reads in 9i and 10g
As I mentioned in this previous blog, we were hoping to use Resource Profiles on our 10.2 data warehouse instance to limit the resources that user queries can use while we have some significant batch jobs running. We were setting the LOGICAL_READS_PER_CALL resource limit but noticed that some user queries had run quite happily for 10 minutes or so, chewing up resources and slowing down the batch jobs. When we investigated, we noticed that those queries were using parallel execution slaves and realised that LOGICAL_READS_PER_CALL isn't going to limit what the slaves do as they're using direct path i/o operations, which aren't counted as logical reads. e.g. (On Oracle 10.2)

SQL> connect / as sysdba
Connected.
SQL> select resource_name, limit from dba_profiles;

RESOURCE_NAME                    LIMIT
-------------------------------- ----------------------------------------
COMPOSITE_LIMIT                  UNLIMITED
SESSIONS_PER_USER                UNLIMITED
CPU_PER_SESSION                  UNLIMITED
CPU_PER_CALL                     UNLIMITED
LOGICAL_READS_PER_SESSION        UNLIMITED
LOGICAL_READS_PER_CALL           10000
IDLE_TIME                        UNLIMITED
CONNECT_TIME                     UNLIMITED
PRIVATE_SGA                      UNLIMITED
FAILED_LOGIN_ATTEMPTS            10
PASSWORD_LIFE_TIME               UNLIMITED
PASSWORD_REUSE_TIME              UNLIMITED
PASSWORD_REUSE_MAX               UNLIMITED
PASSWORD_VERIFY_FUNCTION         NULL
PASSWORD_LOCK_TIME               UNLIMITED
PASSWORD_GRACE_TIME              UNLIMITED

16 rows selected.

SQL> alter system set resource_limit=true;

System altered.

SQL> connect testuser/testuser
Connected.
SQL> select table_name, blocks from user_tables where table_name = 'TEMP';

TABLE_NAME                         BLOCKS
------------------------------ ----------
TEMP                                15873

SQL> select count(*) from temp;
select count(*) from temp
             *
ERROR at line 1:
ORA-02395: exceeded call limit on IO usage


SQL> select /*+ parallel(temp, 2) */ count(*) from temp;

COUNT(*)
----------
1000000

So far so good; logical, but awkward for us. While I was playing around, though, I noticed that if I set a limit for LOGICAL_READS_PER_SESSION then the parallel queries would be terminated. e.g.

SQL> connect / as sysdba
Connected.
SQL> alter profile default limit logical_reads_per_call unlimited;

Profile altered.

SQL> alter profile default limit logical_reads_per_session 10000;

Profile altered.

SQL> connect testuser/testuser
Connected.
SQL> select count(*) from temp;
select count(*) from temp
               *
ERROR at line 1:
ORA-02394: exceeded session  limit on IO usage, you are being logged off

SQL> connect testuser/testuser
Connected.
SQL> select /*+ parallel(temp, 2) */ count(*) from temp;
select /*+ parallel(temp, 2) */ count(*) from temp
*
ERROR at line 1:
ORA-02394: exceeded session limit on IO usage, you are being logged off

So as far as 10.2 is concerned, blocks read by px slaves aren't logical i/o when counting the call usage, but they are when counting the session usage. As Jonathan Lewis said in a comment on the original blog

I think the reason for the contradictory aspect of this behaviour is that someone has fiddled with the code for "session logical reads" in 10g, and not done so properly.

You will probably find that the statistic "session logical reads" (in your test) matches "consistent gets"; and that "consistent gets" is the sum of "consistent gets from cache" and "consistent gets direct".

So let's check that then. I'm going to use Tom Kyte's runstats package for this, something I confess I haven't used much, but it does exactly what I'm looking for here.

SQL> connect / as sysdba
Connected.
SQL> alter system set resource_limit=false;

System altered.

SQL> connect testuser/testuser
Connected.
SQL> exec runstats_pkg.rs_start;

PL/SQL procedure successfully completed.

SQL> select /*+ parallel(temp, 2) */ count(*) from temp;

COUNT(*)
----------
1000000

SQL> exec runstats_pkg.rs_stop;

PL/SQL procedure successfully completed.

SQL> select * from stats where name like '%session logical reads%';

NAME
-----------------------------------------------------------------------
 VALUE
----------
STAT...session logical reads
 16085


SQL> select * from stats where name like '%consistent gets%';

NAME
-----------------------------------------------------------------------
 VALUE
----------
STAT...consistent gets
 16020

STAT...consistent gets from cache
   147

STAT...consistent gets - examination
     2

STAT...consistent gets direct
 15873

So it looks like Jonathan's right (well, the numbers are close enough for my satisfaction). I wonder how the same job looks on 9.2?

[oracle@ISP4400 ~]$ sqlplus "/ as sysdba"

SQL*Plus: Release 9.2.0.4.0 - Production on Mon May 8 23:39:29 2006

Copyright (c) 1982, 2002, Oracle Corporation.  All rights reserved.


Connected to:
Oracle9i Enterprise Edition Release 9.2.0.4.0 - Production
With the Partitioning, OLAP and Oracle Data Mining options
JServer Release 9.2.0.4.0 - Production

SQL> connect / as sysdba
Connected.
SQL> alter system set resource_limit=false;

System altered.

SQL> connect testuser/testuser
Connected.
SQL> exec runstats_pkg.rs_start;

PL/SQL procedure successfully completed.

SQL> select /*+ parallel(temp, 2) */ count(*) from temp;


COUNT(*)
----------
  999999

SQL> SQL> exec runstats_pkg.rs_stop;

PL/SQL procedure successfully completed.

SQL> select * from stats where name like '%session logical reads%';

NAME
-----------------------------------------------------------------------
   VALUE
----------
STAT...session logical reads
    1164


SQL> select * from stats where name like '%consistent gets%';

NAME
-----------------------------------------------------------------------
   VALUE
----------
STAT...consistent gets
   16010

STAT...consistent gets - examination
       5

In the end, I realise this is all a little esoteric. For day to day use, it's best to forget about using any of the LOGICAL_READS% limits if you're using PX. It's probably best to use Resource Manager in those cases.

Disabling PX at the Session Level
So we can't use LOGICAL_READS_PER_CALL to limit the workload of an individual call using Resource Profiles because the bulk of the i/o workload takes place in the px slaves, which use direct path operations. One of the solutions we've considered is a login trigger that stops certain users using PX during the batch window. Something like this :-

CREATE OR REPLACE TRIGGER disable_px
AFTER LOGON ON DATABASE
DECLARE
vdb_resource_limit v$parameter.value%TYPE;
BEGIN

IF USER IN ('READ_ONLY', 'REPORTING', 'BURNSD') THEN
SELECT value INTO vdb_resource
FROM v$parameter
WHERE name = 'resource_limit';

IF vdb_resource = 'TRUE' THEN
EXECUTE IMMEDIATE 'ALTER SESSION DISABLE PARALLEL QUERY';
END IF;
END IF;
END;
/

This should force user sessions to use serial execution and therefore have their resource usage capped by the Resource Profiles. One down-side to this approach is that this won't stop an already-connected user from using PX but that's not a problem in our case because the first stage of our batch process is to kick all of the users out. At that point, they can reconnect to run queries while the batch process proceeds, but at least we're guaranteed that they'll have to log in.

I couldn't get this trigger to prevent PX usage, despite faffing around with it for a while. Eventually I decided to just try the ALTER SESSION command manually. This is on 10.2, but I got similar results from 9.2

[oracle@ISP4400 ~]$ sqlplus testuser

SQL*Plus: Release 10.2.0.1.0 - Production on Mon May 8 19:12:37 2006

Copyright (c) 1982, 2005, Oracle.  All rights reserved.

Enter password:

Connected to:
Oracle Database 10g Enterprise Edition Release 10.2.0.1.0 - Production
With the Partitioning, OLAP and Data Mining options

SQL> set autotrace on
SQL> alter session disable parallel query;

Session altered.

SQL> select /*+ parallel(test_tab1, 2) */ count(*) from test_tab1;

COUNT(*)
----------
65536000


Execution Plan
----------------------------------------------------------
Plan hash value: 1614812727

--------------------------------------------------------------------------------
-------------------------

| Id  | Operation              | Name      | Rows  | Cost (%CPU)| Time     |
TQ  |IN-OUT| PQ Distrib |

--------------------------------------------------------------------------------
-------------------------

|   0 | SELECT STATEMENT       |           |     1 |   606K  (1)| 03:34:54 |
|      |            |

|   1 |  SORT AGGREGATE        |           |     1 |            |          |
|      |            |

|   2 |   PX COORDINATOR       |           |       |            |          |
|      |            |

|   3 |    PX SEND QC (RANDOM) | :TQ10000  |     1 |            |          |  Q1
,00 | P->S | QC (RAND)  |

|   4 |     SORT AGGREGATE     |           |     1 |            |          |  Q1
,00 | PCWP |            |

|   5 |      PX BLOCK ITERATOR |           |    65M|   606K  (1)| 03:34:54 |  Q1
,00 | PCWC |            |

|   6 |       TABLE ACCESS FULL| TEST_TAB1 |    65M|   606K  (1)| 03:34:54 |  Q1
,00 | PCWP |            |

--------------------------------------------------------------------------------
-------------------------



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

SQL>

So what's going on there, then? I also checked the contents of v$px_process while the query was running.

SQL> select * from v$px_process;

SERV STATUS           PID SPID                SID    SERIAL#
---- --------- ---------- ------------ ---------- ----------
P000 IN USE            10 28124                17         41
P001 IN USE            11 28126                12         90

You could argue that the hint explicitly over-rides the session level setting, but that's not how the documentation read to me the first few times I read it.

"You disable parallel SQL execution with an ALTER SESSION DISABLE PARALLEL DML|DDL|QUERY statement. All subsequent DML (INSERT, UPDATE, DELETE), DDL (CREATE, ALTER), or query (SELECT) operations are executed serially after such a statement is issued. They will be executed serially regardless of any PARALLEL clause associated with the statement or parallel attribute associated with the table or indexes involved."
I suppose it doesn't specifically say 'hint' and 'PARALLEL clause' means something different, but I think it's pretty easy to misinterpret that. If my code isn't hinted, but uses the DEGREE setting on the table instead, the ALTER SESSION command does prevent the query from running in parallel.

[oracle@ISP4400 ~]$ sqlplus testuser

SQL*Plus: Release 10.2.0.1.0 - Production on Mon May 8 20:56:37 2006

Copyright (c) 1982, 2005, Oracle.  All rights reserved.

Enter password:

Connected to:
Oracle Database 10g Enterprise Edition Release 10.2.0.1.0 - Production
With the Partitioning, OLAP and Data Mining options

SQL> select table_name, degree from user_tables;

TABLE_NAME                     DEGREE
------------------------------ ------------------------------
TEST_TAB1                               8
TEST_TAB2                               1
DUDE                                    1
TEMP                                    1

SQL> set autotrace on
SQL> select count(*) from test_tab1;

COUNT(*)
----------
65536000


Execution Plan
----------------------------------------------------------
Plan hash value: 1614812727

--------------------------------------------------------------------------------
-------------------------

| Id  | Operation              | Name      | Rows  | Cost (%CPU)| Time     |
TQ  |IN-OUT| PQ Distrib |

--------------------------------------------------------------------------------
-------------------------

|   0 | SELECT STATEMENT       |           |     1 | 84269   (1)| 00:29:51 |
|      |            |

|   1 |  SORT AGGREGATE        |           |     1 |            |          |
|      |            |

|   2 |   PX COORDINATOR       |           |       |            |          |
|      |            |

|   3 |    PX SEND QC (RANDOM) | :TQ10000  |     1 |            |          |  Q1
,00 | P->S | QC (RAND)  |

|   4 |     SORT AGGREGATE     |           |     1 |            |          |  Q1
,00 | PCWP |            |

|   5 |      PX BLOCK ITERATOR |           |    65M| 84269   (1)| 00:29:51 |  Q1
,00 | PCWC |            |

|   6 |       TABLE ACCESS FULL| TEST_TAB1 |    65M| 84269   (1)| 00:29:51 |  Q1
,00 | PCWP |            |

--------------------------------------------------------------------------------
-------------------------



Statistics
----------------------------------------------------------
821  recursive calls
3  db block gets
1119199  consistent gets
1118211  physical reads
680  redo size
413  bytes sent via SQL*Net to client
385  bytes received via SQL*Net from client
2  SQL*Net roundtrips to/from client
7  sorts (memory)
0  sorts (disk)
1  rows processed

SQL> alter session disable parallel query;

Session altered.

SQL> select count(*) from test_tab1
2  /

COUNT(*)
----------
65536000


Execution Plan
----------------------------------------------------------
Plan hash value: 1745491793

------------------------------------------------------------------------
| Id  | Operation          | Name      | Rows  | Cost (%CPU)| Time     |
------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |           |     1 |   607K  (1)| 03:35:14 |
|   1 |  SORT AGGREGATE    |           |     1 |            |          |
|   2 |   TABLE ACCESS FULL| TEST_TAB1 |    65M|   607K  (1)| 03:35:14 |
------------------------------------------------------------------------


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

But, when I hint the code, it over-rides the session setting.

 SQL> select /*+ parallel(test_tab1) */ count(*)
2  from test_tab1;
COUNT(*)
----------
65536000


Execution Plan
----------------------------------------------------------
Plan hash value: 1614812727

--------------------------------------------------------------------------------
-------------------------

| Id  | Operation              | Name      | Rows  | Cost (%CPU)| Time     |
TQ  |IN-OUT| PQ Distrib |

--------------------------------------------------------------------------------
-------------------------

|   0 | SELECT STATEMENT       |           |     1 |   606K  (1)| 03:34:54 |
|      |            |

|   1 |  SORT AGGREGATE        |           |     1 |            |          |
|      |            |

|   2 |   PX COORDINATOR       |           |       |            |          |
|      |            |

|   3 |    PX SEND QC (RANDOM) | :TQ10000  |     1 |            |          |  Q1
,00 | P->S | QC (RAND)  |

|   4 |     SORT AGGREGATE     |           |     1 |            |          |  Q1
,00 | PCWP |            |

|   5 |      PX BLOCK ITERATOR |           |    65M|   606K  (1)| 03:34:54 |  Q1
,00 | PCWC |            |

|   6 |       TABLE ACCESS FULL| TEST_TAB1 |    65M|   606K  (1)| 03:34:54 |  Q1
,00 | PCWP |            |

--------------------------------------------------------------------------------
-------------------------



Statistics
----------------------------------------------------------
61  recursive  calls
3  db block gets
1119092  consistent gets
1118207  physical reads
632  redo size
413  bytes sent via SQL*Net to client
385  bytes received via SQL*Net from client
2  SQL*Net roundtrips to/from client
1  sorts (memory)
0  sorts (disk)
1  rows processed

I suppose it's not that big a deal, but I think it would be an easy mistake to think that using a login trigger could completely disable PX at the session level, but it appears that it won't work if you have hinted code.

We have a problem on one of the data warehouse databases at work. There is an overnight resource profile in place that is designed to stop any users from running long-running queries while other activities are happening. The main limit is on logical_reads_per_call, for example (and this is just a simple example I've been playing with at home)

SQL> alter profile default limit logical_reads_per_call 10000;

Profile altered.

Now I'll connect to the testuser account and look at the table I'm going to test this with - DUDE (why it's called that should become clearer when I blog about DUDE soon)

SQL> select table_name, blocks from user_tables where table_name = 'DUDE';

TABLE_NAME                         BLOCKS
------------------------------ ----------
DUDE                                25431

So you can see that the table DUDE consists of 25431 blocks. Therefore, if I try to perform a full table scan of it, I'll hit the limit.

SQL> set autotrace trace statistics
SQL> select count(*) from dude;
select count(*) from dude
*
ERROR at line 1:
ORA-02395: exceeded call limit on IO usage

But, if I try the same query using parallel execution, it doesn't exceed the limit.

SQL> select /*+ parallel(dude, 2) */ count(*) from dude;

Statistics
----------------------------------------------------------
       27  recursive calls
        3  db block gets
    25537  consistent gets
    25403  physical reads
      672  redo size
      414  bytes sent via SQL*Net to client
      385  bytes received via SQL*Net from client
        2  SQL*Net roundtrips to/from client
        1  sorts (memory)
        0  sorts (disk)
        1  rows processed

And even if I reduce the limit to 500 :-

SQL> connect / as sysdba
Connected.
SQL> alter profile default limit logical_reads_per_call 500;

Profile altered.

SQL> connect testuser/testuser
Connected.
SQL> set autotrace trace statistics
SQL> select /*+ parallel(dude, 2) */ count(*) from dude;

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

There are only two slaves in use, each of which is clearly reading more than 500 blocks, but I assume that because they're background processes, their statistics aren't included.

I'm still digging around with this, but I'm interested in hearing anyone else's experiences because this is causing us a problem because just when we want to limit system load, some of the most resource-hungry SQL statements are being executed and not limited, because they're using PX. I can think of several solutions to this, but it would appear that the existing approach isn't going to work.

Additional info
I missed this off the original post. At work I was using x$ksuru to try to work out what was going on. These are the results I'm getting locally, which show that the original slaves are exceeding the limit that's still in place. (Note that this is on a bigger table, though, to give me more chance to monitor the changes)

select * from x$ksuru
where addr IN (select saddr from v$px_session where qcsid = &parent)
and ksurind = 4

SQL> /
Enter value for parent: 1073
old   2: where addr IN (select saddr from v$px_session where qcsid = &parent)
new   2: where addr IN (select saddr from v$px_session where qcsid = 1073)

ADDR           INDX    INST_ID   KSUSEIDL    KSURIND    KSURUSE
-------- ---------- ---------- ---------- ---------- ----------
7D0532C4       1069          1          1          4      50090
7D057D94       1073          1          1          4         26
7D05DB18       1078          1          1          4      49302

SQL> /
Enter value for parent: 1073
old   2: where addr IN (select saddr from v$px_session where qcsid = &parent)
new   2: where addr IN (select saddr from v$px_session where qcsid = 1073)

ADDR           INDX    INST_ID   KSUSEIDL    KSURIND    KSURUSE
-------- ---------- ---------- ---------- ---------- ----------
7D0532C4       1069          1          1          4      55499
7D057D94       1073          1          1          4         26
7D05DB18       1078          1          1          4      54508