Страницы

суббота, 11 мая 2019 г.

Concatenation and filter subqueries oddity

While investigating a poor query performance issue, I came across the following Real-Time SQL Monitoring report from a 12.1 database:
Global Stats
========================================================================================
| Elapsed |   Cpu   |    IO    | Concurrency | PL/SQL  | Fetch | Buffer | Read | Read  |
| Time(s) | Time(s) | Waits(s) |  Waits(s)   | Time(s) | Calls |  Gets  | Reqs | Bytes |
========================================================================================
|    3041 |     299 |     2742 |        0.00 |      29 |    21 |    27M |  10M |  79GB |
========================================================================================

SQL Plan Monitoring Details (Plan Hash Value=511311330)
========================================================================================================================================================================================================
| Id |                    Operation                     |      Name       |  Rows   | Cost  |   Time    | Start  | Execs |   Rows   | Read  | Read  |  Mem  | Activity |        Activity Detail        |
|    |                                                  |                 | (Estim) |       | Active(s) | Active |       | (Actual) | Reqs  | Bytes | (Max) |   (%)    |          (# samples)          |
========================================================================================================================================================================================================
|  0 | SELECT STATEMENT                                 |                 |         |       |      2822 |    +93 |     1 |     2044 |       |       |       |     1.65 | Cpu (39)                      |
|    |                                                  |                 |         |       |           |        |       |          |       |       |       |          | db file sequential read (9)   |
|  1 |   HASH GROUP BY                                  |                 |       1 |       |         1 |  +2914 |     1 |     2044 |       |       |    1M |          |                               |
|  2 |    CONCATENATION                                 |                 |         |       |      2911 |     +4 |     1 |        0 |       |       |       |          |                               |
|  3 |     FILTER                                       |                 |         |       |           |        |     1 |          |       |       |       |          |                               |
|  4 |      FILTER                                      |                 |         |       |           |        |     1 |          |       |       |       |          |                               |
|  5 |       PARTITION LIST SINGLE                      |                 |       1 |   34M |           |        |       |          |       |       |       |          |                               |
|  6 |        TABLE ACCESS BY LOCAL INDEX ROWID BATCHED | DRIVING_TAB     |       1 |   34M |           |        |       |          |       |       |       |          |                               |
|  7 |         INDEX RANGE SCAN                         | DRIVING_TAB_I   |     36M |  368K |           |        |       |          |       |       |       |          |                               |
|  8 |      INDEX RANGE SCAN                            | DICT_PK         |       1 |     3 |      2911 |     +4 |  334K |     304K |  1169 |   9MB |       |     0.24 | Cpu (5)                       |
|    |                                                  |                 |         |       |           |        |       |          |       |       |       |          | db file sequential read (2)   |
|  9 |     FILTER                                       |                 |         |       |      2911 |     +4 |     1 |    42816 |       |       |       |     0.03 | Cpu (1)                       |
| 10 |      FILTER                                      |                 |         |       |      2911 |     +4 |     1 |     450K |       |       |       |          |                               |
| 11 |       PARTITION LIST SINGLE                      |                 |       1 |   19M |      2911 |     +4 |     1 |     450K |       |       |       |          |                               |
| 12 |        TABLE ACCESS BY LOCAL INDEX ROWID BATCHED | DRIVING_TAB     |       1 |   19M |      2915 |     +0 |     1 |     450K |   10M |  79GB |       |    88.71 | Cpu (72)                      |
|    |                                                  |                 |         |       |           |        |       |          |       |       |       |          | db file parallel read (2453)  |
|    |                                                  |                 |         |       |           |        |       |          |       |       |       |          | db file scattered read (5)    |
|    |                                                  |                 |         |       |           |        |       |          |       |       |       |          | db file sequential read (55)  |
| 13 |         INDEX RANGE SCAN                         | DRIVING_TAB_I   |     20M | 63566 |      2911 |     +4 |     1 |      25M | 78518 | 613MB |       |     8.30 | Cpu (5)                       |
|    |                                                  |                 |         |       |           |        |       |          |       |       |       |          | db file sequential read (237) |
| 14 |      INDEX RANGE SCAN                            | DICT_PK         |       1 |     3 |      2911 |     +4 |  334K |     304K |       |       |       |          |                               |
========================================================================================================================================================================================================
It is quite unusual that line 8 has any number of executions and rows at all as there are no rows returned from line 4-7.
It is also suspicious that the certain activity columns precisely matches line 14.
I decided to take a look at that query using row source executions statistics:
----------------------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                                      | Name            | Starts | E-Rows | A-Rows |   A-Time   | Buffers | Reads  |  OMem |  1Mem | Used-Mem |
----------------------------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                               |                 |      1 |        |   2044 |00:48:34.11 |      26M|     10M|       |       |          |
|   1 |  HASH GROUP BY                                 |                 |      1 |      1 |   2044 |00:48:34.11 |      26M|     10M|  1553K|   956K| 1364K (0)|
|   2 |   CONCATENATION                                |                 |      1 |        |  42816 |00:44:40.63 |      26M|     10M|       |       |          |
|*  3 |    FILTER                                      |                 |      1 |        |      0 |00:00:00.01 |       0 |      0 |       |       |          |
|*  4 |     FILTER                                     |                 |      1 |        |      0 |00:00:00.01 |       0 |      0 |       |       |          |
|   5 |      PARTITION LIST SINGLE                     |                 |      0 |      1 |      0 |00:00:00.01 |       0 |      0 |       |       |          |
|*  6 |       TABLE ACCESS BY LOCAL INDEX ROWID BATCHED| DRIVING_TAB     |      0 |      1 |      0 |00:00:00.01 |       0 |      0 |       |       |          |
|*  7 |        INDEX RANGE SCAN                        | DRIVING_TAB_I   |      0 |     35M|      0 |00:00:00.01 |       0 |      0 |       |       |          |
|*  8 |     INDEX RANGE SCAN                           | DICT_PK         |    333K|      1 |    304K|00:00:18.49 |    1610K|   1173 |       |       |          |
|*  9 |    FILTER                                      |                 |      1 |        |  42816 |00:44:40.57 |      26M|     10M|       |       |          |
|* 10 |     FILTER                                     |                 |      1 |        |    449K|00:47:48.59 |      25M|     10M|       |       |          |
|  11 |      PARTITION LIST SINGLE                     |                 |      1 |      1 |    449K|00:47:47.97 |      25M|     10M|       |       |          |
|* 12 |       TABLE ACCESS BY LOCAL INDEX ROWID BATCHED| DRIVING_TAB     |      1 |      1 |    449K|00:47:47.34 |      25M|     10M|       |       |          |
|* 13 |        INDEX RANGE SCAN                        | DRIVING_TAB_I   |      1 |     19M|     24M|00:03:59.62 |   79436 |  78518 |       |       |          |
|* 14 |     INDEX RANGE SCAN                           | DICT_PK         |    333K|      1 |    304K|00:00:18.49 |    1610K|   1173 |       |       |          |
----------------------------------------------------------------------------------------------------------------------------------------------------------------
Again, it does not make any sense that line 8 is reported as being executed. The number of logical reads does not add up either.
A-Time of INDEX RANGE SCAN DICT_PK is the same in lines 8 and 14, so that I would chalk it up to a statistics reporting bug.

I constructed the following test case used to reproduce the issue and tested it in 12.2, 18.3, 19.2 with the same results:
create table t_driving (status char(1), driving_to_inner_id int);
insert into t_driving values ('A', 1);
insert into t_driving values ('B', 2);
create table t_inner(id int);
insert into t_inner select 1 from dual connect by level<=10;

var status varchar2(1)='B'

begin
  for test_rec in (
    select /*+ use_concat(or_predicates(1)) gather_plan_statistics no_unnest(@inner)*/
           *
      from t_driving
     where (:status='B' and status = 'B' or :status='A' and status = 'A')
       and not exists (
             select /*+ qb_name(inner) */
                    null
               from t_inner
              where id = driving_to_inner_id
           )
  )
  loop 
    null;
  end loop;
  for plan_rec in (select * from table(dbms_xplan.display_cursor( format=> 'allstats last')))
  loop
    dbms_output.put_line(plan_rec.plan_table_output);
  end loop;
end;
/
Here is the output of the last block highlighting the plan execution details:
SQL_ID  4n8swkt3cv3sh, child number 0
-------------------------------------
SELECT /*+ use_concat(or_predicates(1)) gather_plan_statistics
no_unnest(@inner)*/ * FROM T_DRIVING WHERE (:B1 ='B' AND STATUS = 'B'
OR :B1 ='A' AND STATUS = 'A') AND NOT EXISTS ( SELECT /*+
qb_name(inner) */ NULL FROM T_INNER WHERE ID = DRIVING_TO_INNER_ID )
Plan hash value: 3020335025
--------------------------------------------------------------------------------------------
| Id  | Operation            | Name      | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
--------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT     |           |      1 |        |      1 |00:00:00.01 |      14 |
|   1 |  CONCATENATION       |           |      1 |        |      1 |00:00:00.01 |      14 |
|*  2 |   FILTER             |           |      1 |        |      0 |00:00:00.01 |       0 |
|*  3 |    FILTER            |           |      1 |        |      0 |00:00:00.01 |       0 |
|*  4 |     TABLE ACCESS FULL| T_DRIVING |      0 |      1 |      0 |00:00:00.01 |       0 |
|*  5 |    TABLE ACCESS FULL | T_INNER   |      1 |      1 |      0 |00:00:00.01 |       7 |
|*  6 |   FILTER             |           |      1 |        |      1 |00:00:00.01 |      14 |
|*  7 |    FILTER            |           |      1 |        |      1 |00:00:00.01 |       7 |
|*  8 |     TABLE ACCESS FULL| T_DRIVING |      1 |      1 |      1 |00:00:00.01 |       7 |
|*  9 |    TABLE ACCESS FULL | T_INNER   |      1 |      1 |      0 |00:00:00.01 |       7 |
--------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - filter( IS NULL)
3 - filter(:B1='A')
4 - filter("STATUS"='A')
5 - filter("ID"=:B1)
6 - filter( IS NULL)
7 - filter(:B1='B')
8 - filter(("STATUS"='B' AND (LNNVL(:B1='A') OR LNNVL("STATUS"='A'))))
9 - filter("ID"=:B1)
The total number of buffers is 14, which is correct. However, line 5 has also contributed to 7 buffers somehow. Thus there should have been 21 buffers overall.
If line 4 is not executed, as it has starts 0, how come that line 5 is being executed?
I rechecked all the numbers against V$SQL_PLAN_STATISTICS_ALL, V$SQLAREA_PLAN_HASH and other views. The total executions details, such as buffers, were fine - they were all reported as 14.
The only issue was with line 5 - it should have not been reported as being executed or generating any number of logical I/O.
I believe that is a reporting bug - there should be no starts for line 5 at all.

I was curious how new 12.2 OR-Expansion transformation would behave.
Although I knew it could be forced by using an OR_EXPAND hint, I was struggling to get it work, so that I had to resort to optimizer traces to find out why my hints were not honored by the optimizer.
I found the following lines in the trace file that helped solve that issue:
ORE: Predicate chain after QB validity check - SEL$1
(:B1='B' AND "T_DRIVING"."STATUS"='B' OR :B2='A' AND "T_DRIVING"."STATUS"='A') AND  NOT EXISTS (SELECT /*+ NO_UNNES
T QB_NAME ("INNER") */ 0 FROM "T_INNER" "T_INNER")
ORE: Checking validity of disjunct chain
ORE: Bypassed for disjunct chain: No Index or Partition driver found.
ORE: # conjunction chain - 1
ORE: No state generated.
So there is 'No Index or Partition driver found' - that is something that I can work with. It is interesting enough that the Concatenation transformation does not have those restrictions as far as I am aware. At least, it can be forced for the same query with the same objects.

I recreated the driving table using the following commands:
drop table t_driving;
create table t_driving (
  status char(1), 
  driving_to_inner_id int)
partition by list(status) (
  partition values ('A'), 
  partition values ('B'));
insert into t_driving values ('A', 1);
insert into t_driving values ('B', 2);
Then I ran the query below:
begin
  for test_rec in (
    select /*+ or_expand gather_plan_statistics no_unnest(@inner)*/
           *
      from t_driving
     where (:status='B' and status = 'B' or :status='A' and status = 'A')
       and not exists (
             select /*+ qb_name(inner) */
                    null
               from t_inner
              where id = driving_to_inner_id
           )
  )
  loop 
    null;
  end loop;
  for plan_rec in (select * from table(dbms_xplan.display_cursor( format=> 'allstats last')))
  loop
    dbms_output.put_line(plan_rec.plan_table_output);
  end loop;
end;
/
That had the following execution plan:
SQL_ID  16q8nc7mcy3b0, child number 0
-------------------------------------
SELECT /*+ or_expand gather_plan_statistics no_unnest(@inner)*/ * FROM
T_DRIVING WHERE (:B1 ='B' AND STATUS = 'B' OR :B1 ='A' AND STATUS =
'A') AND NOT EXISTS ( SELECT /*+ qb_name(inner) */ NULL FROM T_INNER
WHERE ID = DRIVING_TO_INNER_ID )
Plan hash value: 1055582790
-------------------------------------------------------------------------------------------------------
| Id  | Operation                 | Name            | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
-------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT          |                 |      1 |        |      1 |00:00:00.01 |      44 |
|   1 |  VIEW                     | VW_ORE_95B37148 |      1 |      2 |      1 |00:00:00.01 |      44 |
|   2 |   UNION-ALL               |                 |      1 |        |      1 |00:00:00.01 |      44 |
|*  3 |    FILTER                 |                 |      1 |        |      1 |00:00:00.01 |      44 |
|*  4 |     FILTER                |                 |      1 |        |      1 |00:00:00.01 |      37 |
|   5 |      PARTITION LIST SINGLE|                 |      1 |      1 |      1 |00:00:00.01 |      37 |
|   6 |       TABLE ACCESS FULL   | T_DRIVING       |      1 |      1 |      1 |00:00:00.01 |      37 |
|*  7 |     TABLE ACCESS FULL     | T_INNER         |      1 |      1 |      0 |00:00:00.01 |       7 |
|*  8 |    FILTER                 |                 |      1 |        |      0 |00:00:00.01 |       0 |
|*  9 |     FILTER                |                 |      1 |        |      0 |00:00:00.01 |       0 |
|  10 |      PARTITION LIST SINGLE|                 |      0 |      1 |      0 |00:00:00.01 |       0 |
|* 11 |       TABLE ACCESS FULL   | T_DRIVING       |      0 |      1 |      0 |00:00:00.01 |       0 |
|* 12 |     TABLE ACCESS FULL     | T_INNER         |      0 |      1 |      0 |00:00:00.01 |       0 |
-------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
3 - filter( IS NULL)
4 - filter(:B1='B')
7 - filter("ID"=:B1)
8 - filter( IS NULL)
9 - filter(:B1='A')
11 - filter((LNNVL(:B1='B') OR LNNVL("STATUS"='B')))
12 - filter("ID"=:B1)
Notice that there are no executions in line 10 to 12 - that is how it should be.

TL;DR: a Concatenation transformation with filter subqueries may over-report actual execution statistics, so that the totals, such as Buffers, are fine, however, the plan lines related to filter sub-queries are reported as being executed and having the same execution statistics as their corresponding lines in other concatenation branches.
Those subqueries are not really executed but just are reported as being so.
Thankfully, the 12.2 OR-Expansion transformation is not susceptible to that issue - the execution statistics are reported back as zero for those subqueries which are not actually executed because they are eliminated in the parent filter branches.
The code is this article has been tested against 12.2, 18.3, and 19.2.

понедельник, 8 апреля 2019 г.

PL/SQL Create or Replace Optimization

Oracle said in their Student Guide for 12c that a local user cannot utilize system privileges on a common user's schema.
When I initially checked that preposition, I was a little bit puzzled by the following behavior:
TC@PDB> create or replace procedure c##tc.p
  2  is
  3  begin
  4    null;
  5  end;
  6  /

Procedure created.

TC@PDB>
TC@PDB> create or replace procedure c##tc.p
  2  is
  3  begin
  4    null;
  5    null; -- second null
  6  end;
  7  /
create or replace procedure c##tc.p
*
ERROR at line 1:
ORA-01031: insufficient privileges
I drew a proper conclusion back then that Oracle generally tries to be as lazy as possible, so that if it could not do something, it would probably would not do it.
Like in the example above, if Oracle knows that the source code is the same and all PL/SQL settings are the same, why bother? It just reports back as if the code had been compiled when actually Oracle compared the stored source and its PL/SQL settings with whatever a user supplied.
Although it seems a sound approach, I did not have enough proves that Oracle definitely works in such a way with PL/SQL units.
However, last week I listened to an excellent Bryn Llewellyn's one day seminar where we were discussing Edition-Based Redefinition (EBR) topics and Bryn said exactly the same thing - PL/SQL does have an optimization to not recompile stored units when the supplied code is the same (it was roughly something like that).
It rang a bell and made me return to that issue discovered a few years ago.

Let's make an initial setup and reproduce the error:
SYS@CDB$ROOT> conn / as sysdba
Connected.

SYS@CDB$ROOT> create user c##tc identified by oracle;

User created.

SYS@CDB$ROOT> grant connect, create procedure to c##tc container=all;

Grant succeeded.

SYS@CDB$ROOT>
SYS@CDB$ROOT> conn c##tc/oracle@pdb
Connected.
C##TC@PDB>
C##TC@PDB> create or replace procedure c##tc.p
  2  is
  3  begin
  4    null;
  5  end;
  6  /

Procedure created.

C##TC@PDB>
C##TC@PDB> conn sys/oracle@pdb as sysdba
Connected.
SYS@PDB>
SYS@PDB> grant alter session, connect, create any procedure to tc identified by tc;

Grant succeeded.

SYS@PDB> conn tc/tc@pdb
Connected.
TC@PDB>
TC@PDB> create or replace procedure c##tc.p
  2  is
  3  begin
  4    null;
  5  end;
  6  /

Procedure created.

TC@PDB>
TC@PDB> create or replace procedure c##tc.p
  2  is
  3  begin
  4    null;
  5    null; -- second null
  6  end;
  7  /
create or replace procedure c##tc.p
*
ERROR at line 1:
ORA-01031: insufficient privileges

I reexecute the same create or replace statement with sql trace enabled so as to confirm that it is effectively a noop operation - Oracle does not really recompile that procedure.
While looking into the trace file, the last executed statement is this:
PARSING IN CURSOR #140098350838112 len=54 dep=1 uid=0 oct=3 lid=0 tim=228489468158 hv=696375357 ad='c49fffc0' sqlid='9gq78x8ns3q1x'
select source from source$ where obj#=:1 order by line
END OF STMT
Once I got this, I decided to obtain a short stack of Oracle functions to see what function in Oracle kernel causes that SQL to be executed:
TC@PDB> alter session set events 'sql_trace[sql:9gq78x8ns3q1x] trace("%s\n", shortstack())';

Session altered.
TC@PDB> create or replace procedure c##tc.p
  2  is
  3  begin
  4    null;
  5  end;
  6  /

Procedure created.
The interesting part in the trace file is below:
kkscsCheckCriteria<-kkscsCheckCursor<-kkscsSearchChildList<-kksfbc<-kkspsc0<-kksParseCursor<-opiosq0<-opiall0<-opikpr<-opiodr<-rpidrus<-skgmstack<-rpiswu2<-kprball<-kqlsrclod<-kqllod_new<-kqllod<-kglobld<-kglobpn<-kglpim<-kglpin<-kkx_same_src<-kkpcrt<-opies
kxstGetSqlTraceLevel<-kkscsCheckCriteria<-kkscsCheckCursor<-kkscsSearchChildList<-kksfbc<-kkspsc0<-kksParseCursor<-opiosq0<-opiall0<-opikpr<-opiodr<-rpidrus<-skgmstack<-rpiswu2<-kprball<-kqlsrclod<-kqllod_new<-kqllod<-kglobld<-kglobpn<-kglpim<-kglpin<-kkx_s
opiexe<-opiall0<-opikpr<-opiodr<-rpidrus<-skgmstack<-rpiswu2<-kprball<-kqlsrclod<-kqllod_new<-kqllod<-kglobld<-kglobpn<-kglpim<-kglpin<-kkx_same_src<-kkpcrt<-opiexe<-opiosq0<-kpoal8<-opiodr<-ttcpip<-opitsk<-opiino<-opiodr<-opidrv<-sou2o<-opimai_real<-ssthrs
kxstGetSqlTraceLevel<-opiexe<-opiall0<-opikpr<-opiodr<-rpidrus<-skgmstack<-rpiswu2<-kprball<-kqlsrclod<-kqllod_new<-kqllod<-kglobld<-kglobpn<-kglpim<-kglpin<-kkx_same_src<-kkpcrt<-opiexe<-opiosq0<-kpoal8<-opiodr<-ttcpip<-opitsk<-opiino<-opiodr<-opidrv<-sous
Notice that sequence: kkpcrt -> kkx_same_src I was quite curious about that kkx_same_src as it looked like an explanation of that fictional compilation, so I just disassembled it and found these two assembler instructions below in the output:
gdb $ORACLE_HOME/bin/oracle
GNU gdb (GDB) Red Hat Enterprise Linux 7.6.1-114.el7
Copyright (C) 2013 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-redhat-linux-gnu".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from /u01/app/oracle/product/12.1.0/dbhome_1/bin/oracle...(no debugging symbols found)...done.
(gdb) disassemble kkx_same_src
Dump of assembler code for function kkx_same_src:
... skip ...
   0x0000000002b8703f <+479>:   mov    $0x291b,%edi
   0x0000000002b87044 <+484>:   callq  0xceafa20 <dbkdchkeventrdbmserr>
There is an event 0x291b that can influence that function! Let's try this out:
TC@PDB> alter session set events '0x291b level 1';

Session altered.

TC@PDB> create or replace procedure c##tc.p
  2  is
  3  begin
  4    null;
  5  end;
  6  /
create or replace procedure c##tc.p
*
ERROR at line 1:
ORA-01031: insufficient privileges


TC@PDB> alter session set events '0x291b off';

Session altered.

TC@PDB> create or replace procedure c##tc.p
  2  is
  3  begin
  4    null;
  5  end;
  6  /

Procedure created.
Indeed, it does effect the execution. The next step is to find out what this event is:
[oracle@localhost ~]$ echo 'ibase=16;291B' | bc
10523
[oracle@localhost ~]$ oerr ora 10523
10523, 00000, "force recreate package even if definition is unchanged"
// *Cause:
// *Action:  Set this event only under the supervision of Oracle development
// *Comment: Changes behaviour of create or replace package, procedure,
//           function or type to force recreation of the object even if its new
//           definition exactly matches the old definition.
//           No level number required.
That event was the last missing piece in this puzzle.

TL;DR: as any good software, Oracle tries to do as little work as possible - this is a laziness in its good sense.
After all, the fastest way to do something is to not do it at all.
That what happens here - if there is no need to compile a PL/SQL unit, Oracle can identify it and report back to the user that the PL/SQL has been compiled when really it was not. That optimization is controlled by event 10523.
However, it kicks in early, before other Multitenant related checks, namely Oracle does not check whether a local user actually can compile a stored PL/SQL unit in a common schema.
I believe that is a bug as there should be an ORA-1031 error in the first place, even when the source is the same.
Everything said is applicable only to 12.1.0.2 on which it has been tested.

суббота, 30 марта 2019 г.

wget one liners to download data from *.oracle.com without human intervention

When the topic of downloading Oracle software comes up, there is a common misconception that it requires a human intervention to accept the license terms.
Here are wget commands that I use to download data from Oracle sites, such as edelivery.oracle.com, download.oracle.com, and support.oracle.com:
wget \
  --user "<oracleaccount>" \
  --ask-password \
  --load-cookies <(printf '.oracle.com\tTRUE\t/\tFALSE\t0\toraclelicense\taccept-securebackup-cookie') \
  "<https_downloadlink>"
Or its fully automatic version:
wget \
  --user "<oracleaccount>" \
  --password "<password>" \
  --load-cookies <(printf '.oracle.com\tTRUE\t/\tFALSE\t0\toraclelicense\taccept-securebackup-cookie') \
  "<https_downloadlink>"
It has been tested against all of those sites and works fine as of now.
A few examples are below.
edelivery.oracle.com:
wget \
  --user "<oracleaccount>" \
  --ask-password \
  --load-cookies <(printf '.oracle.com\tTRUE\t/\tFALSE\t0\toraclelicense\taccept-securebackup-cookie') \
  "https://edelivery.oracle.com/akam/otn/linux/oracle18c/xe/oracle-database-xe-18c-1.0-1.x86_64.rpm"
download.oracle.com:
wget \
  --user "<oracleaccount>" \
  --ask-password \
  --load-cookies <(printf '.oracle.com\tTRUE\t/\tFALSE\t0\toraclelicense\taccept-securebackup-cookie') \
  "https://download.oracle.com/otn/linux/oracle18c/xe/oracle-database-xe-18c-1.0-1.x86_64.rpm"
support.oracle.com - this one does not require the cookie:
wget \
  --user "<oracleaccount" \
  --ask-password \
  "https://updates.oracle.com/Orion/Services/download/p6880880_180000_Linux-x86-64.zip?aru=22569537&patch_file=p6880880_180000_Linux-x86-64.zip"

воскресенье, 17 марта 2019 г.

Bitmap Conversion to Rowids with Global Indexes

While working with developers on optimizing a query, I discovered a limitation of the "BITMAP AND" operation.
Here is an example demonstrating the issue:
SQL> create table t(
  2    part_col int,
  3    a int,
  4    b int)
  5  partition by list(part_col) (
  6    partition values (0)
  7  )
  8  ;

Table created.

SQL>
SQL> exec dbms_stats.gather_table_stats('', 't')

PL/SQL procedure successfully completed.

SQL>
SQL> create index t_a_i on t(a);

Index created.

SQL> create index t_b_i on t(b) local;

Index created.

SQL>
SQL> explain plan for
  2  select /*+ bitmap_tree(t and((a) (b)))*/
  3         *
  4    from t
  5   where a = :1
  6     and b = :2;

Explained.

SQL>
SQL> select * from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
-----------------------------------------------------------------------------------------------------------------------------
Plan hash value: 1636314338

--------------------------------------------------------------------------------------------------------------------
| Id  | Operation                                  | Name  | Rows  | Bytes | Cost (%CPU)| Time     | Pstart| Pstop |
--------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                           |       |     1 |    39 |     1   (0)| 00:00:01 |       |       |
|*  1 |  TABLE ACCESS BY GLOBAL INDEX ROWID BATCHED| T     |     1 |    39 |     1   (0)| 00:00:01 |     1 |     1 |
|*  2 |   INDEX RANGE SCAN                         | T_A_I |     1 |       |     1   (0)| 00:00:01 |       |       |
--------------------------------------------------------------------------------------------------------------------

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

   1 - filter("B"=TO_NUMBER(:2))
   2 - access("A"=TO_NUMBER(:1))

15 rows selected.
Surprisingly, the plan shows just one INDEX RANGE SCAN operation and the expected BITMAP AND did not happen.
Let us see what we get once we make both indexes local:
SQL> drop index t_a_i;

Index dropped.

SQL> drop index t_b_i;

Index dropped.

SQL> create index t_a_i on t(a) local;

Index created.

SQL> create index t_b_i on t(b) local;

Index created.

SQL>
SQL> explain plan for
  2  select /*+ bitmap_tree(t and((a) (b)))*/
  3         *
  4    from t
  5   where a = :1
  6     and b = :2;

Explained.

SQL>
SQL> select * from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
-----------------------------------------------------------------------------------------------------------------------------
Plan hash value: 3534803727

--------------------------------------------------------------------------------------------------------------------
| Id  | Operation                                  | Name  | Rows  | Bytes | Cost (%CPU)| Time     | Pstart| Pstop |
--------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                           |       |     1 |    39 |     3   (0)| 00:00:01 |       |       |
|   1 |  PARTITION LIST SINGLE                     |       |     1 |    39 |     3   (0)| 00:00:01 |     1 |     1 |
|   2 |   TABLE ACCESS BY LOCAL INDEX ROWID BATCHED| T     |     1 |    39 |     3   (0)| 00:00:01 |     1 |     1 |
|   3 |    BITMAP CONVERSION TO ROWIDS             |       |       |       |            |          |       |       |
|   4 |     BITMAP AND                             |       |       |       |            |          |       |       |
|   5 |      BITMAP CONVERSION FROM ROWIDS         |       |       |       |            |          |       |       |
|*  6 |       INDEX RANGE SCAN                     | T_A_I |       |       |     1   (0)| 00:00:01 |     1 |     1 |
|   7 |      BITMAP CONVERSION FROM ROWIDS         |       |       |       |            |          |       |       |
|*  8 |       INDEX RANGE SCAN                     | T_B_I |       |       |     1   (0)| 00:00:01 |     1 |     1 |
--------------------------------------------------------------------------------------------------------------------

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

   6 - access("A"=TO_NUMBER(:1))
   8 - access("B"=TO_NUMBER(:2))

21 rows selected.
Here it is. Once I made both indexes local, the "BITMAP AND" operation showed up.
Initially, I thought that it might have been related to different rowid's formats used for global and local indexes.
I just inserted one row to the table and dumped the leaf block for the global and local indexes:
$ grep 'col ' global.trc local.trc
global.trc:col 0; len 2; (2):  c1 02
global.trc:col 1; len 10; (10):  00 01 67 82 02 80 13 69 00 00
local.trc:col 0; len 2; (2):  c1 02
local.trc:col 1; len 6; (6):  02 80 13 69 00 00
You see that 'col 1' for the local index has a rowid in it: "len 6; (6): 02 80 13 69 00 00",
whereas the corresponding column for the global index has 10 bytes in length: "len 10; (10): 00 01 67 82 02 80 13 69 00 00"
In which the leading 4 bytes refer to the object id.
I also performed additional tests trying all possible combinations of indexes T_A_I and T_B_I making them global or local.
The only case when I was getting a "BITMAP AND" was the case when both indexes were local.
Changing the hint to INDEX_COMBINE has not changed anything.

Having gathered all of those results, I searched My Oracle Support (MOS) and found the explanation:
Bug 8787683 : SUPPORT GLOBAL BITMAP INDEXES AND BITMAP CONVERSION ON GLOBAL BTREE INDEXES
There is, indeed, the enhancement request raised in 2009.

The source query was rewritten to combine both indexes early and use filtered rowids to access the base table:
SQL> explain plan for
  2  select /*+ unnest(@subq) no_use_hash_aggregation(@subq)*/
  3         *
  4    from t
  5   where rowid in (
  6           select /*+ qb_name(subq)*/
  7                  rid
  8             from (select rowid rid
  9                     from t
 10                    where a = :1
 11                    union all
 12                   select rowid
 13                     from t
 14                    where b = :2)
 15            group by rid
 16            having count(*)=2)
 17  ;

Explained.

SQL>
SQL> select * from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
-----------------------------------------------------------------------------------------------------------------------------
Plan hash value: 4066617294

--------------------------------------------------------------------------------------------------------
| Id  | Operation                   | Name     | Rows  | Bytes | Cost (%CPU)| Time     | Pstart| Pstop |
--------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |          |     1 |    63 |     5  (40)| 00:00:01 |       |       |
|   1 |  NESTED LOOPS               |          |     1 |    63 |     5  (40)| 00:00:01 |       |       |
|   2 |   VIEW                      | VW_NSO_1 |     2 |    24 |     3  (34)| 00:00:01 |       |       |
|*  3 |    FILTER                   |          |       |       |            |          |       |       |
|   4 |     SORT GROUP BY           |          |     1 |    24 |     3  (34)| 00:00:01 |       |       |
|   5 |      VIEW                   |          |     2 |    24 |     2   (0)| 00:00:01 |       |       |
|   6 |       UNION-ALL             |          |       |       |            |          |       |       |
|*  7 |        INDEX RANGE SCAN     | T_A_I    |     1 |    25 |     1   (0)| 00:00:01 |       |       |
|   8 |        PARTITION LIST SINGLE|          |     1 |    25 |     1   (0)| 00:00:01 |     1 |     1 |
|*  9 |         INDEX RANGE SCAN    | T_B_I    |     1 |    25 |     1   (0)| 00:00:01 |     1 |     1 |
|  10 |   TABLE ACCESS BY USER ROWID| T        |     1 |    51 |     1   (0)| 00:00:01 |     1 |     1 |
--------------------------------------------------------------------------------------------------------

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

   3 - filter(COUNT(*)=2)
   7 - access("A"=TO_NUMBER(:1))
   9 - access("B"=TO_NUMBER(:2))
Notice the "SORT GROUP BY" operation in line 4 - it guarantees that the set of ROWIDs will be sorted, so that we will never return to a block that was previously visited once we switched to another.

TL;DR: the "BITMAP AND" operation has some restrictions when Global indexes are involved: Bug 8787683 : SUPPORT GLOBAL BITMAP INDEXES AND BITMAP CONVERSION ON GLOBAL BTREE INDEXES
The code was tested against 12.1.0.2 and 19c available on https://livesql.oracle.com

понедельник, 25 февраля 2019 г.

Index full scan min/max scans returning wrong results on partitioned tables

A developer has recently shown me an interesting wrong results issue in one of our 12.1.0.2 databases.
Having investigated it, I identified the root cause of that issue and constructed a simple test case that can be used to reproduce it.
Let's setup some sample data - a list-partitioned table with just two rows and a global index:
SQL> create table t (
  2    id,
  3    part_key,
  4    constraint t_pk primary key(id))
  5  partition by list(part_key) (
  6    partition values ('KEY1'),
  7    partition values ('KEY2'))
  8  as
  9  select 1, 'KEY1' from dual union all
 10  select 2, 'KEY2' from dual;

Table created.

SQL>
SQL> col part_key for a8
SQL> select *
  2    from t;

        ID PART_KEY
---------- --------
         1 KEY1
         2 KEY2

Here are queries returning wrong results:
SQL> select max(id)
  2    from t
  3   where part_key = 'KEY1';

   MAX(ID)
----------
         2

SQL> select min(id)
  2    from t
  3   where part_key = 'KEY2';

   MIN(ID)
----------
         1

They should have returned 1 and 2 correspondingly. Things definitely went awry.
In such a scenario, I always try to figure out how exactly the optimizer comes up with the result.
The execution plan is a good place to start:
SQL> select * from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
-----------------------------------------------------------------------------------------------
Plan hash value: 2094033419

-----------------------------------------------------------------------------------
| Id  | Operation                  | Name | Rows  | Bytes | Cost (%CPU)| Time     |
-----------------------------------------------------------------------------------
|   0 | SELECT STATEMENT           |      |     1 |    19 |     2   (0)| 00:00:01 |
|   1 |  SORT AGGREGATE            |      |     1 |    19 |            |          |
|   2 |   INDEX FULL SCAN (MIN/MAX)| T_PK |     1 |    19 |            |          |
-----------------------------------------------------------------------------------

Note
-----
   - dynamic statistics used: dynamic sampling (level=2)

13 rows selected.
Aha! There is no way for the optimizer to answer that query by using that execution plan.
Where is the PART_KEY predicate? It seems to have been completely lost there.
A quick search on MOS got me a candidate issue: Bug 22913528 - wrong results with partition pruning and min/max scans (Doc ID 22913528.8)
That document mentions a workaround which I successfully implemented:
SQL> select /*+ opt_param('_fix_control' '16346018:0')*/
  2         max(id)
  3    from t
  4   where part_key = 'KEY1';

   MAX(ID)
----------
         1

SQL>
The plan of that query is below:
SQL> select * from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
-----------------------------------------------------------------------------------------------
Plan hash value: 2831600127

-----------------------------------------------------------------------------------------------
| Id  | Operation              | Name | Rows  | Bytes | Cost (%CPU)| Time     | Pstart| Pstop |
-----------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT       |      |     1 |    19 |     2   (0)| 00:00:01 |       |       |
|   1 |  SORT AGGREGATE        |      |     1 |    19 |            |          |       |       |
|   2 |   PARTITION LIST SINGLE|      |     1 |    19 |     2   (0)| 00:00:01 |     1 |     1 |
|   3 |    TABLE ACCESS FULL   | T    |     1 |    19 |     2   (0)| 00:00:01 |     1 |     1 |
-----------------------------------------------------------------------------------------------

Note
-----
   - dynamic statistics used: dynamic sampling (level=2)

14 rows selected.
The MOS document says that this issue has been fixed in the 12.1.0.2.190115 (Jan 2019) Database Proactive Bundle Patch.

воскресенье, 30 апреля 2017 г.

Asynchronous Global Index Maintenance and Recycle Bin

Got Oracle error ORA-38301: "can not perform DDL/DML over objects in Recycle Bin" in an alert.log:
ORCL(3):Errors in file /u01/app/oracle/diag/rdbms/orcl12c/orcl12c/trace/orcl12c_j000_10274.trc:
ORA-12012: error on auto execute of job "SYS"."PMO_DEFERRED_GIDX_MAINT_JOB"
ORA-38301: can not perform DDL/DML over objects in Recycle Bin
ORA-06512: at "SYS.DBMS_PART", line 131
ORA-06512: at "SYS.DBMS_PART", line 131
ORA-06512: at "SYS.DBMS_PART", line 120
ORA-06512: at line 1
The highlighted line indicates that the error relates to the automatic scheduler job SYS.PMO_DEFERRED_GIDX_MAINT_JOB, which was introduced in the Oracle database 12.1 release.
It is responsible for cleaning up indexes after drop/truncate operations: link.
I delved into the issue and found that the job SYS.PMO_DEFERRED_GIDX_MAINT_JOB did not ignore objects in the Recycle Bin.
Here is a short test case to demonstrate that:
SQL> select banner from v$version;

BANNER
--------------------------------------------------------------------------------
Oracle Database 12c Enterprise Edition Release 12.2.0.1.0 - 64bit Production
PL/SQL Release 12.2.0.1.0 - Production
CORE    12.2.0.1.0      Production
TNS for Linux: Version 12.2.0.1.0 - Production
NLSRTL Version 12.2.0.1.0 - Production

SQL> create table t(x)
  2  partition by range(x)
  3  (
  4    partition values less than(maxvalue)
  5  )
  6  as
  7  select 1
  8    from dual;

Table created.

SQL>
SQL> create index t_i on t(x);

Index created.

SQL>
SQL> alter table t truncate partition for(1) update indexes;

Table truncated.

SQL>
SQL> select status, orphaned_entries
  2    from ind
  3   where index_name = 'T_I';

STATUS   ORP
-------- ---
VALID    YES

SQL>
SQL> drop table t;

Table dropped.
Now I run the job SYS.PMO_DEFERRED_GIDX_MAINT_JOB manually as if it was running automatically:
SQL> select run_count, failure_count, state from user_scheduler_jobs where job_name='PMO_DEFERRED_GIDX_MAINT_JOB';

 RUN_COUNT FAILURE_COUNT STATE
---------- ------------- --------------------
         4             0 SCHEDULED

SQL>  exec dbms_scheduler.run_job( 'PMO_DEFERRED_GIDX_MAINT_JOB', false)

PL/SQL procedure successfully completed.

SQL>  select run_count, failure_count, state from user_scheduler_jobs where job_name='PMO_DEFERRED_GIDX_MAINT_JOB';

 RUN_COUNT FAILURE_COUNT STATE
---------- ------------- --------------------
         5             1 SCHEDULED

The job SYS.PMO_DEFERRED_GIDX_MAINT_JOB calls the DBMS_PART.CLEANUP_GIDX_INTERNAL procedure.
The same ORA-38301 error can be raised if I call the DBMS_PART.CLEANUP_GIDX procedure:
SQL> exec DBMS_PART.CLEANUP_GIDX (user)
BEGIN DBMS_PART.CLEANUP_GIDX (user); END;

*
ERROR at line 1:
ORA-38301: can not perform DDL/DML over objects in Recycle Bin
ORA-06512: at "SYS.DBMS_PART", line 131
ORA-06512: at "SYS.DBMS_PART", line 131
ORA-06512: at "SYS.DBMS_PART", line 120
ORA-06512: at "SYS.DBMS_PART", line 193
ORA-06512: at line 1
The problem here is that the automatic job stops further processing on any error.
It means that we may end up having lots of indexes requiring cleanup that are not processed automatically and have to undergone manual actions to reset their state.

tl;dr. Although the Asynchronous Global Index Maintenance feature is quite useful and can greatly speedup the partition maintenance operations TRUNCATE PARTITION and DROP PARTITION, it still does not ignore objects in the Recycle Bin.
Therefore, the automatic maintenance job PMO_DEFERRED_GIDX_MAINT_JOB may fail and does not process all of the indexes that require cleanup.

среда, 15 марта 2017 г.

SQL*Plus 12.2 and searching path of login.sql

Having installed Oracle Database 12.2 on a client, I have noticed that the login.sql script, which is placed in a custom directory specified by SQLPATH, is not invoked anymore.
Here is my login.sql:
[oracle@localhost]$ cat /tmp/sqlpath/login.sql 
select 'login.sql invoked' output 
  from dual;
The login.sql script is not invoked when I connect through SQL*Plus 12.2 despite the fact the SQLPATH environment variable is set:
[oracle@localhost]$ export SQLPATH=/tmp/sqlpath
[oracle@localhost]$ sqlplus tc/tc@ora12

SQL*Plus: Release 12.2.0.1.0 Production on Wed Mar 15 09:20:52 2017

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

Last Successful login time: Wed Mar 15 2017 09:16:06 +07:00

Connected to:
Oracle Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit Production
With the Partitioning, Automatic Storage Management, OLAP, Advanced Analytics,
Real Application Testing and Unified Auditing options

SQL> 

This issue is documented in SQL*Plus 12.2.0.1.0 Change in Behavior for Search Path of Login.sql (SQL*Plus User Profile Script) (Doc ID 2241021.1).
Unsurprisignly, if I set ORACLE_PATH, then login.sql is invoked:
[oracle@localhost]$ export ORACLE_PATH=$SQLPATH
[oracle@localhost]$ unset SQLPATH
[oracle@localhost]$ sqlplus tc/tc@ora12

SQL*Plus: Release 12.2.0.1.0 Production on Wed Mar 15 09:21:13 2017

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

Last Successful login time: Wed Mar 15 2017 09:20:52 +07:00

Connected to:
Oracle Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit Production
With the Partitioning, Automatic Storage Management, OLAP, Advanced Analytics,
Real Application Testing and Unified Auditing options


OUTPUT
---------------------------------------------------
login.sql invoked

SQL> 

The MOS note also contains information that this new behaviour may influence earlier releases when the PSU or CI are released for them.
I have no idea why Oracle has changed the existing functionality with login.sql, but that is definitely something to keep in mind in case you are going to upgrade to a new release.
Interestingly, SQLcl still honor SQLPATH even when both SQLPATH and ORACLE_PATH are set:
[oracle@localhost]$ cat /tmp/sqlpath/login.sql
select 'login.sql invoked' output 
  from dual;
[oracle@localhost]$ cat /tmp/oracle_path/login.sql
select 'oracle_path invoked'
  from dual;
[oracle@localhost]$ export ORACLE_PATH=/tmp/oracle_path
[oracle@localhost]$ export SQLPATH=/tmp/sqlpath
[oracle@localhost]$ ./sql tc/tc@ora12

SQLcl: Release 12.2.0.1.0 RC on Ср мар 15 09:42:08 2017

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

Connected to:
Oracle Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit Production
With the Partitioning, Automatic Storage Management, OLAP, Advanced Analytics,
Real Application Testing and Unified Auditing options


OUTPUT           
-----------------
login.sql invoked