Monday, June 13, 2016

SQL Parsing in serializable transaction throws ORA-08177: can't serialize access for this transaction

Setting serializable isolation level in Oracle 12c (12.1.0.2.0), SQL Parsing can throw:
  ORA-08177: can't serialize access for this transaction

run test (see Blog appended TestCode):
 
SQL (742) > exec ora_08177_test(10, 'ksun_ora_08177_collect_listagg');

Run=1
ERROR at line 1:
ORA-08177: can't serialize access for this transaction
ORA-06512: at "ORA_08177_TEST", line 20
ORA-06512: at line 1

Note: Each time, open a new session, run the test. After first run, subsequent runs in the same session do not hit the error.

According to Oracle documentation: Database Concepts - Data Concurrency and Consistency

The database generates an error when a serializable transaction tries to update or delete data changed by a different transaction that committed after the serializable transaction began:
 ORA-08177: Cannot serialize access for this transaction


Here there exists only one single session, so it does not satisfy the requirement of above documentation.

Reasoning


Refer to the recursive session discussed in Blog: Oracle 12c single session "library cache lock (cycle)" deadlock .

run query:
 
select distinct s.sid, holding_user_session, holding_session
  from v$libcache_locks c, v$session s
 where lnnvl(holding_user_session = holding_session)
   and c.holding_user_session = s.saddr 
   and s.sid = 742;
   
SID HOLDING_USER_SES HOLDING_SESSION 
--- ---------------- ----------------
742 070001010ECF8680 070001010ECFC880    

(742 is the SID of test session)

crosscheck the dump generated by 8177 trace event on AIX (we set this event for the test):

----- Call Stack Trace -----
ktrexc()+3536        call     ksesecl0()           FFFFFFFFFFC9FB0 ? 122F5F490 ?
rpidrv()+3572        call     rpiswu2()            70001010ECFC880 ? 1221BF1E0 ?
kksLoadChild()+3544  call     rpiswu2()            70001010ECF8680 ? 000000090 ?
...
========== FRAME [19] (ktrexc()+3536 -> ksesecl0()) ==========
defined by frame pointers 0xffffffffffca080  and 0xffffffffffc9ee0
CALL TYPE: call   ERROR SIGNALED: yes   COMPONENT: (null)
...
PROCESS STATE
-------------
Process global information:
     process: 0x70001010e8c4078, call: 0x7000100eb0e7bb0, xact: 0x7000101037e9880, 
     curses: 0x70001010ecfc880, usrses: 0x70001010ecf8680
...
KSUSETRN = 0X07000101037E9880
...
(trans) flg = 0x00000004, flg2 = 0x00400000, flg3 = 0x00000040, 
  prx = 0x7000101037e9880, ros = 2147483647, crtses=0x70001010ecf8680

we can establish two equations:

holding_user_session = 070001010ECF8680 = usrses: 0x70001010ecf8680
holding_session      = 070001010ECFC880 = curses: 0x70001010ecfc880

which tellingly indicate the co-existence of two different sessions, usrses(user session) and curses (cursor session), and existence of transaction (0X07000101037E9880) created by user session (crtses=0x70001010ecf8680).

Looking Call Stack Trace, user session calls:
   kksLoadChild()
and then switches to cursor session, which triggers rpi (recursive procedure interface):
 rpidrv()
and finally ERROR SIGNALED at:
  ktrexc()
where ktr means kernel transaction read consistency.

Since user session already started a transaction, any attempt to modify the data by the cursor session resulted in:
 ORA-08177: can't serialize access for this transaction

Run other two tests:

SQL (742) > exec ora_08177_test(10, 'ksun_ora_08177_collect');
SQL (742) > exec ora_08177_test(10, 'ksun_ora_08177_listagg');

there are no errors.

Hence, the error is probably related to certain constellation of collect and listagg.

All tests are performed on AIX, Solaris and Linux with Oracle 12c (12.1.0.2.0).
It is not reproducible in Oracle 11.2.0.4.0.

By the way, the first run of query:

SQL (742)> select collect (y) from ksun_ora_08177;
SYSTPNSRcj9+JXnjgVAAmVdl5Ow==(1, 2, 3, 0, 1, 2, 3, 0, 1)

creates a new TYPE:

TYPE     "SYSTPNSRcj9+JXnjgVAAmVdl5Ow==" AS TABLE OF NUMBER

which is due to "COLLECT" function.

It can be verified by:

select s.*, o.last_ddl_time, o.created, o.*
  from dba_source s, dba_objects o
 where s.name = o. object_name
   and o.object_type = 'TYPE'
   and name = 'SYSTPNSRcj9+JXnjgVAAmVdl5Ow==';

and also documented in Database SQL Language Reference:

COLLECT is an aggregate function that takes as its argument a column of any type
and creates a nested table of the input type out of the rows selected.


Another example of TYPE creation was observed in Blog: Oracle 12c single session "library cache lock (cycle)" deadlock.

Addendum


It seems that fixing such a bug requires a lot of design change in the code, for example, distinguishing user DML and sys DML on underlying objects (e.g. undo$ or user$ tables). For the time being, fixing the bug is not feasible. Therefore be cautious when using such features.

TestCode


--------------------
set numformat 99
column y_coll format a10

alter system set events '8177 trace name errorstack level 10';

drop table ksun_ora_08177;

create table ksun_ora_08177 as select mod(level, 2) x, mod(level, 4) y from dual connect by level <= 9; 

select * from ksun_ora_08177;

create or replace type ksun_tab force is table of number;
/

--------------------
create or replace force view ksun_ora_08177_collect_listagg(x, cnt, y_coll) as
with sq as (
  select x, count(*) cnt, cast (collect (distinct y) as ksun_tab) y
  from ksun_ora_08177
  group by x)
select x, cnt,
       (select listagg (column_value, ',') within group (order by column_value)
          from table (y)) y_coll
from sq 
where x is not null;

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

create or replace force view ksun_ora_08177_collect(x, cnt, y_coll) as
select x, count(*) cnt, cast (collect (distinct y) as ksun_tab) y_coll
from ksun_ora_08177
where x is not null
group by x;

--------------------
create or replace force view ksun_ora_08177_listagg(x, cnt, y_coll) as
select x, count(*) cnt, listagg (y, ',') within group (order by y) y_coll
from ksun_ora_08177
where x is not null
group by x;

--------------------
create or replace procedure ora_08177_test(p_cnt number, p_view varchar2) as
 l_cur       integer;
 l_qry       varchar2(300) := 'select * from '||p_view;
 l_idx           pls_integer;
 l_col_desc_tab  dbms_sql.desc_tab;
begin
 l_qry := 'select /* '||p_view ||' */ * from '||p_view;
 for i in 1..p_cnt loop
  dbms_output.put_line('Run='||i);
  execute immediate 'alter system flush shared_pool';

  begin
    commit;
    set transaction isolation level serializable;
    l_cur := dbms_sql.open_cursor;
    dbms_sql.parse(l_cur, l_qry, dbms_sql.native);
    dbms_sql.describe_columns (l_cur, l_idx, l_col_desc_tab);
    dbms_sql.close_cursor(l_cur);
    exception when others then
      dbms_sql.close_cursor(l_cur);
      raise;
  end;
 end loop;
end;
/

-- Note: Each time, open a new session, run the test. After first run, subsequent runs in the same session do not hit the error.
-- exec ora_08177_test(10, 'ksun_ora_08177_collect_listagg');
-- exec ora_08177_test(10, 'ksun_ora_08177_collect');
-- exec ora_08177_test(10, 'ksun_ora_08177_listagg');


Tuesday, May 17, 2016

Oracle Fixed Table Practice

Fixed objects x$ tables and their indexes are memory structures storing run-time information. They are open to outside as normal tables because every thing is Relation (Table) in relational database, principle founded by Edgar F. Codd ("A relational model of data for large shared data banks"). Similar uniform philosophy in UNIX is every thing is file (notably proc filesystem procfs).

This Blog will try to do expose meta data of x$ tables since they are not handled in a uniform way as normal tables. We also take GV$SQL_OPTIMIZER_ENV and its underlined X$KQLFSQCE as example in the queries because this x$ table is dynamic, big, and longer duration of its stats gathering.


1. List all fixed objects


select * from x$kqfta fxt, sys.fixed_obj$ fobj where fobj.obj# = fxt.kqftaobj and fxt.kqftanam in ('X$KQLFSQCE');


2. List indexes of fixed objects

 
select index_number, column_name from gv$indexed_fixed_column where table_name in ('X$KQLFSQCE');
 1 KQLFSQCE_HASH
 2 KQLFSQCE_SQLID  

We can try to verify them by looking the xplan of following queries:

select * from gv$sql_optimizer_env where hash_value = :hash_value;
 FIXED TABLE FIXED INDEX TABLE (FIXED) SYS.X$KQLFSQCE (ind:1)

select * from gv$sql_optimizer_env where sql_id = :sql_id;
 FIXED TABLE FIXED INDEX TABLE (FIXED) SYS.X$KQLFSQCE (ind:2)

select * from gv$sql_optimizer_env where id = :id;   (KQLFSQCE_PNUM)
 FIXED TABLE FULL TABLE (FIXED) SYS.X$KQLFSQCE


3. List histogram of fixed objects


select column_name, histogram from dba_tab_col_statistics 
 where table_name in ('X$KQLFSQCE') and histogram not in ('NONE');
  INST_ID        FREQUENCY
  KQLFSQCE_FLAGS FREQUENCY
 
select distinct table_name, column_name from dba_tab_histograms where table_name in ('X$KQLFSQCE');
 INST_ID
 KQLFSQCE_FLAGS
 
select dbms_stats.report_gather_fixed_obj_stats(detail_level=>'ALL', format=>'TEXT') from dual;
 INST_ID
 KQLFSQCE_HADD
 KQLFSQCE_SQLID
 KQLFSQCE_FLAGS
 KQLFSQCE_PNUM

The above 3 outputs have differences, and we can try to verify them by looking the xplan of following queries:
                                                                                                        
select * from gv$sql_optimizer_env where inst_id = 1;
  FIXED TABLE FULL TABLE (FIXED) SYS.X$KQLFSQCE QBlock Name: SEL$5C160134
    Cost: 1  Bytes: 32,349,932  Cardinality: 376,162

select * from gv$sql_optimizer_env where inst_id = 9;
  FIXED TABLE FULL TABLE (FIXED) SYS.X$KQLFSQCE QBlock Name: SEL$5C160134
    Cost: 1  Bytes: 86  Cardinality: 1

select * from gv$sql_optimizer_env where id = 1;
  FIXED TABLE FULL TABLE (FIXED) SYS.X$KQLFSQCE QBlock Name: SEL$5C160134
    Cost: 1  Bytes: 68,800  Cardinality: 800

select * from gv$sql_optimizer_env where id = 9;
  FIXED TABLE FULL TABLE (FIXED) SYS.X$KQLFSQCE QBlock Name: SEL$5C160134
    Cost: 1  Bytes: 68,800  Cardinality: 800

We can see that two queries on column ID (KQLFSQCE_PNUM) give the same xplan estimation, probably does not have histogram. It is not clear why dbms_stats.report_gather_fixed_obj_stats lists more columns.


4. List stats gathering performance of fixed tables

                                                                                                  
select v.last_analyzed, table_name, num_rows, sample_size, avg_row_len 
      ,(v.last_analyzed - lag(v.last_analyzed) over (order by v.last_analyzed))*86400 seconds 
      ,(num_rows * avg_row_len) bytes 
      ,(sample_size/nullif(num_rows, 0)) sample_ratio 
      ,v.* 
  from dba_tab_statistics v 
 where object_type in ('FIXED TABLE') 
   and v.last_analyzed between timestamp'2016-05-17 09:00:00' and timestamp'2016-05-17 10:00:00' 
order by seconds desc nulls last;       

As a result of above query, we can find the most time consuming of x$ tables in:
  dbms_stats.gather_fixed_objects_stats;
and hence exclude them in next stats gather by calling
  dbms_stats.lock_table_stats


5. Trace x$ table access


On Solaris, run:
     exec dbms_stats.gather_fixed_objects_stats;
and simultaneously watch kqlfsqce call by dtrace script (8694 is PID of above SQL Session):

sudo dtrace -n \
'BEGIN {printf("dtrace started: %Y\n", walltimestamp);}
pid8694:a.out:kqlfsqce: { @[execname, ustack()] = count();} 
END { trunc(@, 10);}
END { printf("dtrace ended: %Y\n", walltimestamp);}'

and stop the tracing once X$KQLFSQCE is gathered, the output looks as:

dtrace: description 'BEGIN ' matched 111 probes
CPU     ID                    FUNCTION:NAME
 17      1                           :BEGIN dtrace started: 2016 May 17 09:13:01
^C
 21      2                             :END
 21      2                             :END dtrace ended: 2016 May 17 09:42:42

  oracle
              oracle`kqlfsqce+0x2c
              oracle`qerfxFetch+0x125f
              oracle`rwsfcd+0x6f
              oracle`qeruaFetch+0x173
              oracle`rwsfcd+0x6f
              oracle`qerltFetch+0x4c8
              oracle`insdlexe+0x202
              oracle`insExecStmtExecIniEngine+0x6b
              oracle`insexe+0x6eb
              oracle`opiexe+0x179f
              oracle`opipls+0x62a
              oracle`opiodr+0x433
              oracle`rpidrus+0xde
              oracle`skgmstack+0x85
              oracle`rpidru+0x88
              oracle`rpiswu2+0x2fd
              oracle`rpidrv+0x589
              oracle`psddr0+0x138
              oracle`psdnal+0x2cd
              oracle`pevm_EXIM+0xf0
          3290001

Crosschecking with output of above sql query, the row for X$KQLFSQCE shows:
  sample_size = 3281070
  seconds = 1736

Monday, April 11, 2016

sql_id and idn to shared pool subpool

Oracle shared pool is divided into a few of subpools(maximum 7). Each sql_id is mapped to its subpool by hash function:
    subpool no = mod(mod(dbms_utility.sqlid_to_sqlhash(sql_id), 131072), subpools) + 1
since
    idn=dbms_utility.sqlid_to_sqlhash (sql_id)
the mapping can be written as:
    subpool no = mod(mod(idn, 131072), subpools) + 1
where subpools is the number of used subpools, which can be observed by:
   select * from v$latch_children where name = 'shared pool';

In the above formula, 131072 is the default Library cache hash table bucket count, which is specified by:
    _kgl_bucket_count    default  9
and Library cache hash table bucket count is computed by:
   (2^_kgl_bucket_count * 256 = 2^(_kgl_bucket_count + 8)) 
    default: 2^(9+8) = 2^17  = 131072
By the way, there are also other KGL hidden parameters:
    _kgl_large_heap_warning_threshold   default 52428800 (51200K or 50MB) 
    maximum heap size before KGL writes warnings to the alert log 
    
    _kgl_large_heap_assert_threshold   default 524288000 (512000K or 500MB)
    maximum heap size before KGL raises an internal error 
    
    _kgl_time_to_wait_for_locks        default 15
    time to wait for locks and pins before timing out
The above hash function can be used to monitor sql_id unbalanced distributions of subpools (see Blog: Shared Pool - Memory Allocation - unbalanced ).


For instance, once seeing the error message:
   ORA-04031: unable to allocate 184 bytes of shared memory ("shared pool","SELECT ...","SQLA^de798f19","179.kggfa")
you can find its subpool by:
   mod(mod(to_number('de798f19', 'xxxxxxxx'), 131072), 7)+ 1 = 5

If majority of such errors occurs in subpool 5, it would be a hint pointing to the unbalanced distributions.


The above formula is verified in Oracle 11gR2 and 12c.

Monday, February 15, 2016

Native Code Files: Ora-7445 [Ioc_pin_shared_executable_object()] Reproducing

PL/SQL and JAVA Native Code Files are used in Oracle to boost performance.

Blog: Remove Stale Native Code Files on AIX discussed the generation and remove of Native Code Files.

Blog: What the heck are the /dev/shm/JOXSHM_EXT_x files on Linux? revealed the contents and loading of Native Code Files.

Both Blogs follow MOS Note Ora-7445 [Ioc_pin_shared_executable_object()] (Doc ID 1316906.1), which said:
  If ORA-7445 [ioc_pin_shared_executable_object] is encountered, one should look into the following:
  1) Is there any user or job that may have tried to clean up files in the directory where the backing store images are located?
  2) Is the location where the backing store files are located out of space?
  3) Is the location where the backing store files are located accessible?

This Blog will try to reproduce the error on Linux with Oracle Version 11.2.0.4.0.

1. PL/SQL Native Code Files


Create Package by:
 alter system set plsql_code_type=native;    
 -- Default  INTERPRETED
 
 create or replace package bla as
   procedure foo;
 end;
 /
 create or replace package body bla as
   procedure foo is begin null; end;
 end;
 /
   
One Native Code File is generated after create package body bla (not generated after create package spec), and stored in tmpfs (/dev/shm/):
   linux: ls -lt /dev/shm/
   -rwx------ 1 oracle dba 424 Feb 12 07:08 PESLD_testdb_56ae0002_b8c1106001000000*

In Sqlplus, run:
 07:09:48 (243,7)>  exec bla.foo;

In Linux, map into the virtual memory of calling process (15022 is PID of Oracle session (243,7)):
  linux: pmap -x 15022
   Address           Kbytes     RSS   Dirty Mode   Mapping
   00007ff61a7cb000       4       4       4 r-x--  PESLD_testdb_56ae0002_b8c1106001000000

  linux: cat /proc/15022/maps
   7ff61a7cb000-7ff61a7cc000 r-xp 00000000 00:0f 21930676  /dev/shm/PESLD_testdb_56ae0002_b8c1106001000000

if we remove it:
  linux: rm /dev/shm/PESLD_testdb_56ae0002_b8c1106001000000

they are marked as "deleted" for PID 15022:

   00007f19bcd64000       4       4       4 r-x--  PESLD_testdb_56ae0002_b8c1106001000000 (deleted)
   7f19bcd64000-7f19bcd65000 r-xp 00000000 00:0f 21618650 /dev/shm/PESLD_testdb_56ae0002_b8c1106001000000 (deleted)

Open a new SQL session, run:
 07:18:07 (325,21) > exec bla.foo;
 ORA-00600: internal error code, arguments: [pesldl01_Get_Object: shm_open failed: errno 2 errmsg No such fil], [/PESLD_testdb_56ae0002_b8c1106001000000]

strace shows:
 open("/dev/shm/PESLD_testdb_56ae0002_b8c1106001000000", O_RDWR|O_NOFOLLOW|O_CLOEXEC) = -1 ENOENT (No such file or directory):
 
occasionally there is incident dump, which shows:
 ORA-07445: exception encountered: core dump [ioc_pin_shared_executable_object()+888] [SIGSEGV] [ADDR:0x0] [PC:0x30E1CD0] [Address not mapped to object] []
 
In the already opened session, it is still OK:
 07:29:48 (243,7) > exec bla.foo;

Native Code Files are stored in tmpfs (/dev/shm/) and there is no locking mechanisms to prevent them from removing by the user. In Linux, tmpfs is one part of cache (see output of command free and vmstat). In case of low memory situations, it could be subject to garbage collection or swapping out.

2. Java JIT Native Code Files


Run
 alter system set java_jit_enabled=true;
 create or replace and compile java source named "Hello" as
  public class Hello {
     public static String world ()
     {
        return "hello world";
     }
  }
 /
 create or replace function helloworld
  return varchar2 as language java
  name 'Hello.world () return java.lang.string';
 /
 select helloworld from dual;

We can see more than 100 files are created after compile java source. They all look like:
 /dev/shm/JOXSHM_EXT_553_testdb_1451786242*


3. Ora-7445 [Ioc_pin_shared_executable_object()] Reproducing


At first restart database by:
 shutdown immediate   
 startup 
 
so that all Native Code Files are cleaned away, no more files under /dev/shm/
(note: "shutdown abort" will not clean up /dev/shm/, see Blog: Remove Stale Native Code Files on AIX).


Open one Plsql session, run a simple query:

 08:07:38 (124,13)> select helloworld from dual;
  hello world
 
and at the same time, one can also watch the process in Linux (51876 id PID of Session 124):

 linux: strace -p 51876 
  open("/dev/shm/JOXSHM_EXT_162_testdb_1454571522", O_RDWR|O_CREAT|O_TRUNC|O_NOFOLLOW|O_CLOEXEC, 0770) = 7
  fchmod(7, 0770)                         = 0
  ftruncate(7, 12288)                     = 0
  write(7, "\0", 1)                       = 1
  lseek(7, 4095, SEEK_CUR)                = 4096
  write(7, "\0", 1)                       = 1
  lseek(7, 4095, SEEK_CUR)                = 8192
  write(7, "\0", 1)                       = 1
  mmap(NULL, 12288, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_SHARED, 7, 0) = 0x7f9f77a52000
  close(7)                                = 0
 
 linux: ls -ltr /dev/shm/* |wc
     167    1503   14258 
     
 linux: pmap -x 51876    
  00007f1fb1b96000       4       4       4 rwxs-  JOXSHM_EXT_47_testdb_1453129730
  ...
  00007f1fb1b97000       4       4       4 rwxs-  JOXSHM_EXT_8_testdb_1453129730
 
Allocate 33GB PGA memory (see Test Code in Blog: Limit PGA Memory Usage):

 08:09:25 (124,13)> exec pga_mem_test.allo(33*1024);
  Start allocate: 3379 > Used/Alloc/Freeable/Max >>> 11/14/1/16
               ------ Category(Alloc/Used/Max) >>> SQL(1/0/5) > PL/SQL(2/2/4) > Other(6//6) > JAVA(4/4/5) > Freeable(1/0/) >
  ORA-04030: out of process memory when trying to allocate 16328 bytes (koh-kghu sessi,pl/sql vc2)
 
 08:09:36 (124,13)> select helloworld from dual;
  hello world
  
 and the trace dump shows:
  Memory (Avail / Total) = 640.90M / 15943.66M
  Swap (Avail / Total) = 8152.43M /  8187.99M
  ioc_allocate(size: 335927, heap name: *** ??? ***, flags: a0008) caught 4030
 
Run a new query, which requires new mmap:
 08:10:31 (124,13)> select dbms_java.get_compiler_option('', 'encoding')from dual;
  ORA-04030: out of process memory when trying to allocate 262224 bytes (joxcx callheap,f:Class)
  ORA-06512: at "SYS.DBMS_JAVA", line 147

continue running that query, get the same error.

and strace shows:
 linux: strace -p 51876
  unlink("/dev/shm/JOXSHM_EXT_162_testdb_1454571522") = 0
  open("/dev/shm/JOXSHM_EXT_162_testdb_1454571522", O_RDWR|O_CREAT|O_TRUNC|O_NOFOLLOW|O_CLOEXEC, 0770) = 19
  fchmod(19, 0770)                        = 0
  ftruncate(19, 12288)                    = 0
  write(19, "\0", 1)                      = 1
  lseek(19, 4095, SEEK_CUR)               = 4096
  write(19, "\0", 1)                      = 1
  lseek(19, 4095, SEEK_CUR)               = 8192
  write(19, "\0", 1)                      = 1
  mmap(NULL, 12288, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_SHARED, 19, 0) = 0x7f9f77a52000
  close(19)        

Open a new session, run the same select:
 08:13:12 (356,7)> select dbms_java.get_compiler_option('', 'encoding')from dual;
  UTF-8

watch the new loaded files:
 linux: ls -ltr /dev/shm|wc
     317    2846   24555

Back to the error session, run the select again:
 08:15:22 (124,13)> select dbms_java.get_compiler_option('', 'encoding')from dual;
  ORA-03113: end-of-file on communication channel
  Process ID: 51876
  Session ID: 124 Serial number: 13
  ORA-03114: not connected to ORACLE
 
and strace said:
 linux: strace -p 51876
  open("/dev/shm/JOXSHM_EXT_2_testdb_1454571522", O_RDWR|O_NOFOLLOW|O_CLOEXEC) = 8
  mmap(NULL, 4096, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_SHARED, 8, 0) = -1 ENOMEM (Cannot allocate memory)
  ...
  --- SIGSEGV {si_signo=SIGSEGV, si_code=SEGV_MAPERR, si_addr=0} ---

The same Native Code File in Session 356 (54806 is PID of Session 356):
 pmap -x 54806 |grep JOXSHM_EXT_2_
  00007ff1785ba000       4       4       4 rwxs-  JOXSHM_EXT_2_testdb_1453719554
  
 (Note that "PROT_READ|PROT_WRITE|PROT_EXEC" are mapped to "rwx", "MAP_SHARED" to "s") 
 

The incident dump of error session shows:
 ORA-07445: exception encountered: core dump [ioc_pin_shared_executable_object()+888] [SIGSEGV] [ADDR:0x0] [PC:0x30E1CD0] [Address not mapped to object] []
 > ioc_pin_shared_executable_object()+888 (0x30e1cd0) mov (%rax),%rdx
 mmap(offset=207478784, len=8192) failed with errno=12 for the file oracletestdb

and the trace dump contains:
 mmap failed with error 12
 error message:Cannot allocate memory
 ORA-04035: unable to allocate 4096 bytes of shared memory in shared object cache "JOXSHM" of size "117440512"
 Assertion failure at joez.c:3422
 Bulk load of method oracle/sql/DatumWithConnection.getPhysicalConnection failed; insufficient shm-object space

(prefix "ioc" in ORA-07445 message could be acronym of "Inversion of Control", something like callbacks)

The same information is also written into MMON_SLAVE dump, for example, M000
 *** MODULE NAME:(MMON_SLAVE) 2016-02-10T07:02:30.076240+01:00
 *** ACTION NAME:(JAVAVM JIT slave action) 2016-02-10T07:02:30.076244+01:00
 ORA-07445: exception encountered: core dump 

With following script, one can watch the allocated size (Kbytes):
  linux: pmap -x 51876 |grep -e PESLD -e JOXSHM |awk '{cnt+=1; Kbytes+=$2; RSS+=$3; Dirty+=$4} END {print "Count=",cnt,",Kbytes=",Kbytes,",RSS=",RSS,",Dirty=",Dirty}'
         Count= 65280 ,Kbytes= 4210688 ,RSS= 4180512 ,Dirty= 4180512


In summary, after a session hits:
  ORA-04030: out of process memory when trying to allocate 262224 bytes (joxcx callheap,f:Class)
and when it wants to load more Native Code Files:
  (1). If the Native Code Files are not found in tmpfs (/dev/shm/), it continues throwing ORA-04030.
  (2). If they are found in tmpfs (which are loaded by other sessions), it throws:
            ORA-07445: exception encountered: core dump [ioc_pin_shared_executable_object()+888] [SIGSEGV]
        and disconnects the session.

Wednesday, January 13, 2016

Performance of Oracle Object Collection Comparisons - Part2

In Blog: Blog Performance of Oracle Object Collection Comparisons - Part1 we discussed two functions: SET, Equal and Not Equal Comparisons. Now we continue to look on other two functions:

COLLECT
    COLLECT is an aggregate function that takes as its argument a column of any type and creates a nested table of the input type out of the rows selected.

Multiset Operators
   Multiset operators combine the results of two nested tables into a single nested table.

1. Setup the test (see appended Test Code)

2. Run the test by:
        truncate table test_stat;
    exec all_test_run_2(4);


3. Wait test finished, query the statistics by:
SET LINES 400
SET NUMWIDTH 12
SET NUMFORMAT 999,999,999
COLUMN TOTAL_COMP_EST_RATIO FORMAT 999.99

select s.*, round(s.total_comp_est/nullif(s.total_comp, 0), 2) total_comp_est_ratio
  from (select t.*, round(10*1000*elapsed/nullif(total_comp, 0), 2) us_per_comp,
         case test_name 
           when 'COLLECT_SORT'                     then round(cnt*ln(cnt)*3)
           when 'COLLECT_SORT_DIST'                then round(cnt*ln(cnt)*3/(greatest(log(10, cnt/disticnt_cnt), 1)))
           when 'COLLECT_DISTINCT'                 then 2*cnt
           when 'COLLECT_DISTINCT_DIST'            then 2*cnt*(greatest(log(10, cnt/disticnt_cnt), 1))
           when 'MULTISET_UNION_ALL'               then 2*cnt
           when 'MULTISET_UNION_ALL_DIST'          then 2*cnt*(greatest(log(10, cnt/disticnt_cnt), 1))
           when 'MULTISET_UNION_DISTINCT'          then 2*cnt
           when 'MULTISET_UNION_DISTINCT_DIST'     then 2*cnt*(greatest(log(10, cnt/disticnt_cnt), 1))
           when 'MULTISET_EXCEPT_ALL'              then 2*cnt
           when 'MULTISET_EXCEPT_ALL_DIST'         then 2*cnt*(greatest(log(10, cnt/disticnt_cnt), 1))
           when 'MULTISET_EXCEPT_DISTINCT'         then 2*cnt
           when 'MULTISET_EXCEPT_DISTINCT_DIST'    then 2*cnt*(greatest(log(10, cnt/disticnt_cnt), 1))
           when 'MULTISET_INTERSECT_ALL'           then 2*cnt
           when 'MULTISET_INTERSECT_ALL_DIST'      then 2*cnt*(greatest(log(10, cnt/disticnt_cnt), 1))
           when 'MULTISET_INTERSECT_DISTINCT'      then 2*cnt
           when 'MULTISET_INTERSECT_DISTINCT_DIST' then 2*cnt*(greatest(log(10, cnt/disticnt_cnt), 1))
         end total_comp_est 
     from test_stat t) s;

returns:

TEST_NAME RUN_ID CNT DISTICNT_CNT ELAPSED TOTAL_COMP SINGLE_COMP US_PER_COMP TOTAL_COMP_EST TOTAL_COMP_EST_RATIO
COLLECT_SORT
1
10
10
0
50
5
0
69
1.38
COLLECT_SORT
2
100
100
2
1278
12.78
15.65
1382
1.08
COLLECT_SORT
3
1000
1000
38
21396
21.396
17.76
20723
0.97
COLLECT_SORT
4
10000
10000
517
302050
30.205
17.12
276310
0.91
COLLECT_SORT_DIST
1
10000
10
117
59990
5.999
19.5
92103
1.54
COLLECT_SORT_DIST
2
10000
100
212
117108
11.7108
18.1
138155
1.18
COLLECT_SORT_DIST
3
10000
1000
322
184044
18.4044
17.5
276310
1.5
COLLECT_SORT_DIST
4
10000
10000
515
302050
30.205
17.05
276310
0.91
COLLECT_DISTINCT
1
10
10
0
26
2.6
0
20
0.77
COLLECT_DISTINCT
2
100
100
1
214
2.14
46.73
200
0.93
COLLECT_DISTINCT
3
1000
1000
5
2020
2.02
24.75
2000
0.99
COLLECT_DISTINCT
4
10000
10000
45
20028
2.0028
22.47
20000
1
COLLECT_DISTINCT_DIST
1
10000
10
105
57968
5.7968
18.11
60000
1.04
COLLECT_DISTINCT_DIST
2
10000
100
200
116242
11.6242
17.21
40000
0.34
COLLECT_DISTINCT_DIST
3
10000
1000
279
164002
16.4002
17.01
20000
0.12
COLLECT_DISTINCT_DIST
4
10000
10000
45
20028
2.0028
22.47
20000
1
MULTISET_UNION_ALL
1
10
10
0
26
2.6
0
20
0.77
MULTISET_UNION_ALL
2
100
100
0
214
2.14
0
200
0.93
MULTISET_UNION_ALL
3
1000
1000
5
2020
2.02
24.75
2000
0.99
MULTISET_UNION_ALL
4
10000
10000
46
20028
2.0028
22.97
20000
1
MULTISET_UNION_ALL_DIST
1
10000
10
104
57968
5.7968
17.94
60000
1.04
MULTISET_UNION_ALL_DIST
2
10000
100
199
116242
11.6242
17.12
40000
0.34
MULTISET_UNION_ALL_DIST
3
10000
1000
280
164002
16.4002
17.07
20000
0.12
MULTISET_UNION_ALL_DIST
4
10000
10000
46
20028
2.0028
22.97
20000
1
MULTISET_UNION_DISTINCT
1
10
10
0
26
2.6
0
20
0.77
MULTISET_UNION_DISTINCT
2
100
100
1
214
2.14
46.73
200
0.93
MULTISET_UNION_DISTINCT
3
1000
1000
4
2020
2.02
19.8
2000
0.99
MULTISET_UNION_DISTINCT
4
10000
10000
46
20028
2.0028
22.97
20000
1
MULTISET_UNION_DISTINCT_DIST
1
10000
10
104
57968
5.7968
17.94
60000
1.04
MULTISET_UNION_DISTINCT_DIST
2
10000
100
199
116242
11.6242
17.12
40000
0.34
MULTISET_UNION_DISTINCT_DIST
3
10000
1000
279
164002
16.4002
17.01
20000
0.12
MULTISET_UNION_DISTINCT_DIST
4
10000
10000
46
20028
2.0028
22.97
20000
1
MULTISET_EXCEPT_ALL
1
10
10
1
26
2.6
384.62
20
0.77
MULTISET_EXCEPT_ALL
2
100
100
0
214
2.14
0
200
0.93
MULTISET_EXCEPT_ALL
3
1000
1000
5
2020
2.02
24.75
2000
0.99
MULTISET_EXCEPT_ALL
4
10000
10000
46
20028
2.0028
22.97
20000
1
MULTISET_EXCEPT_ALL_DIST
1
10000
10
104
57968
5.7968
17.94
60000
1.04
MULTISET_EXCEPT_ALL_DIST
2
10000
100
199
116242
11.6242
17.12
40000
0.34
MULTISET_EXCEPT_ALL_DIST
3
10000
1000
280
164002
16.4002
17.07
20000
0.12
MULTISET_EXCEPT_ALL_DIST
4
10000
10000
46
20028
2.0028
22.97
20000
1
MULTISET_EXCEPT_DISTINCT
1
10
10
0
26
2.6
0
20
0.77
MULTISET_EXCEPT_DISTINCT
2
100
100
1
214
2.14
46.73
200
0.93
MULTISET_EXCEPT_DISTINCT
3
1000
1000
5
2020
2.02
24.75
2000
0.99
MULTISET_EXCEPT_DISTINCT
4
10000
10000
47
20028
2.0028
23.47
20000
1
MULTISET_EXCEPT_DISTINCT_DIST
1
10000
10
104
57968
5.7968
17.94
60000
1.04
MULTISET_EXCEPT_DISTINCT_DIST
2
10000
100
200
116242
11.6242
17.21
40000
0.34
MULTISET_EXCEPT_DISTINCT_DIST
3
10000
1000
280
164002
16.4002
17.07
20000
0.12
MULTISET_EXCEPT_DISTINCT_DIST
4
10000
10000
46
20028
2.0028
22.97
20000
1
MULTISET_INTERSECT_ALL
1
10
10
1
26
2.6
384.62
20
0.77
MULTISET_INTERSECT_ALL
2
100
100
0
214
2.14
0
200
0.93
MULTISET_INTERSECT_ALL
3
1000
1000
5
2020
2.02
24.75
2000
0.99
MULTISET_INTERSECT_ALL
4
10000
10000
46
20028
2.0028
22.97
20000
1
MULTISET_INTERSECT_ALL_DIST
1
10000
10
105
57968
5.7968
18.11
60000
1.04
MULTISET_INTERSECT_ALL_DIST
2
10000
100
200
116242
11.6242
17.21
40000
0.34
MULTISET_INTERSECT_ALL_DIST
3
10000
1000
281
164002
16.4002
17.13
20000
0.12
MULTISET_INTERSECT_ALL_DIST
4
10000
10000
47
20028
2.0028
23.47
20000
1
MULTISET_INTERSECT_DISTINCT
1
10
10
0
26
2.6
0
20
0.77
MULTISET_INTERSECT_DISTINCT
2
100
100
0
214
2.14
0
200
0.93
MULTISET_INTERSECT_DISTINCT
3
1000
1000
5
2020
2.02
24.75
2000
0.99
MULTISET_INTERSECT_DISTINCT
4
10000
10000
46
20028
2.0028
22.97
20000
1
MULTISET_INTERSECT_DISTINCT_DIST
1
10000
10
105
57968
5.7968
18.11
60000
1.04
MULTISET_INTERSECT_DISTINCT_DIST
2
10000
100
201
116242
11.6242
17.29
40000
0.34
MULTISET_INTERSECT_DISTINCT_DIST
3
10000
1000
280
164002
16.4002
17.07
20000
0.12
MULTISET_INTERSECT_DISTINCT_DIST
4
10000
10000
46
20028
2.0028
22.97
20000
1

Test Code


-- At first run Test Code in precedent Blog: "Performance of Oracle Object Collection Comparisons - Part1"
-- (http://ksun-oracle.blogspot.ch/2016/01/performance-of-oracle-object-collection_13.html)

------------------------------- COLLECT_test ---------------------------------
create or replace procedure collect_test (p_name varchar2, p_size number default 1000, p_dist_val pls_integer := null) as
 l_dist_val  number := coalesce(p_dist_val, p_size);
 l_test_name   varchar2(40);
  l_tobj_tab_1  tobj_tab := tobj_tab();
  l_start_time  number;
  l_elapsed     number;
begin
 helper.p_num1_cnt := 0;
 l_start_time := dbms_utility.get_time;
 
 if p_name in ('COLLECT_SORT', 'COLLECT_SORT_DIST') then
  select cast(collect(tobj(num1, num2) order by tobj(num1, num2) desc) as tobj_tab) into l_tobj_tab_1
    from (select level num1, mod(level, l_dist_val) num2 from dual connect by level <= p_size);
 else
  -- Workaround due to PL/SQL: ORA-30482: DISTINCT option not allowed for this function
  -- DISTINCT option works for SQL, but not for PL/SQL  
  execute immediate q'[
   select cast(collect(distinct tobj(num1, num2)) as tobj_tab)
     from (select level num1, mod(level, :p_dist_val) num2 from dual connect by level <= :p_size)]'
   into l_tobj_tab_1 using l_dist_val, p_size; 
 end if;
    
 l_elapsed := dbms_utility.get_time - l_start_time;
 helper.record(p_name, p_size, l_dist_val,
        l_elapsed, helper.p_num1_cnt, (helper.p_num1_cnt/p_size));
 helper.format(p_name||' count=', l_tobj_tab_1.count);
 helper.format('  Total Number of Object Comparisons=', helper.p_num1_cnt);   
end;
/    

--exec collect_test('COLLECT_SORT', 100, 100);
--exec collect_test('COLLECT_SORT_DIST', 100, 10);
--exec collect_test('COLLECT_DISTINCT', 100, 100);
--exec collect_test('COLLECT_DISTINCT_DIST', 100, 10);

create or replace procedure collect_test_run(p_run number) as
begin
 for i in 1..p_run loop collect_test('COLLECT_SORT', power(10, i), power(10, i)); end loop;
 for i in 1..p_run loop collect_test('COLLECT_SORT_DIST', power(10, p_run), power(10, i)); end loop;
 for i in 1..p_run loop collect_test('COLLECT_DISTINCT', power(10, i), power(10, i)); end loop;
 for i in 1..p_run loop collect_test('COLLECT_DISTINCT_DIST', power(10, p_run), power(10, i)); end loop; 
end;
/ 

--exec collect_test_run(3);

------------------------------- MULTISET_test ---------------------------------
create or replace procedure multiset_test (p_name varchar2, p_size number default 1000, p_dist_val pls_integer := null) as
 l_dist_val  number := coalesce(p_dist_val, p_size);
 l_test_name   varchar2(40);
  l_tobj_tab_1  tobj_tab := tobj_tab();
  l_tobj_tab_2 tobj_tab := tobj_tab();
  l_tobj_tab_3 tobj_tab := tobj_tab();
  l_start_time  number;
  l_elapsed     number;
begin
 select cast(multiset(select level, mod(level, l_dist_val) from dual connect by level <= p_size) as tobj_tab) 
  into l_tobj_tab_1 from dual;
 select cast(multiset(select level, mod(level, l_dist_val) from dual connect by level <= p_size) as tobj_tab) 
   into l_tobj_tab_2 from dual;
 
  helper.p_num1_cnt := 0;
  l_start_time := dbms_utility.get_time;
  
  case 
  when p_name in ('MULTISET_UNION_ALL', 'MULTISET_UNION_ALL_DIST') then 
     l_tobj_tab_3 := l_tobj_tab_1 MULTISET UNION ALL l_tobj_tab_2;
  when p_name in ('MULTISET_UNION_DISTINCT', 'MULTISET_UNION_DISTINCT_DIST') then 
     l_tobj_tab_3 := l_tobj_tab_1 MULTISET UNION DISTINCT l_tobj_tab_2;
  when p_name in ('MULTISET_EXCEPT_ALL', 'MULTISET_EXCEPT_ALL_DIST') then 
       l_tobj_tab_3 := l_tobj_tab_1 MULTISET EXCEPT ALL l_tobj_tab_2;
  when p_name in ('MULTISET_EXCEPT_DISTINCT', 'MULTISET_EXCEPT_DISTINCT_DIST') then 
       l_tobj_tab_3 := l_tobj_tab_1 MULTISET EXCEPT DISTINCT l_tobj_tab_2;
  when p_name in ('MULTISET_INTERSECT_ALL', 'MULTISET_INTERSECT_ALL_DIST') then 
       l_tobj_tab_3 := l_tobj_tab_1 MULTISET INTERSECT ALL l_tobj_tab_2;
  when p_name in ('MULTISET_INTERSECT_DISTINCT', 'MULTISET_INTERSECT_DISTINCT_DIST') then 
       l_tobj_tab_3 := l_tobj_tab_1 MULTISET INTERSECT DISTINCT l_tobj_tab_2;
 end case;
 
 l_elapsed := dbms_utility.get_time - l_start_time;
 helper.record(p_name, p_size, l_dist_val,
        l_elapsed, helper.p_num1_cnt, (helper.p_num1_cnt/p_size/2));
 helper.format(p_name||' count=', l_tobj_tab_3.count);  
 helper.format('  Total Number of Object Comparisons=', helper.p_num1_cnt);  
end;
/ 

--exec multiset_test('MULTISET_UNION_ALL', 100, 100);
--exec multiset_test('MULTISET_UNION_DISTINCT', 100, 100);
--exec multiset_test('MULTISET_UNION_DISTINCT_DIST', 100, 10);
--exec multiset_test('MULTISET_EXCEPT_ALL', 100, 100);
--exec multiset_test('MULTISET_EXCEPT_DISTINCT', 100, 100);
--exec multiset_test('MULTISET_INTERSECT_ALL', 100, 100);
--exec multiset_test('MULTISET_INTERSECT_DISTINCT', 100, 100);
--exec multiset_test('MULTISET_INTERSECT_DISTINCT_DIST', 100, 100);

create or replace procedure multiset_test_run(p_run number) as
begin
 for i in 1..p_run loop collect_test('MULTISET_UNION_ALL',    power(10, i),     power(10, i)); end loop;
 for i in 1..p_run loop collect_test('MULTISET_UNION_ALL_DIST', power(10, p_run), power(10, i)); end loop;
 for i in 1..p_run loop collect_test('MULTISET_UNION_DISTINCT',      power(10, i),     power(10, i)); end loop;
 for i in 1..p_run loop collect_test('MULTISET_UNION_DISTINCT_DIST', power(10, p_run), power(10, i)); end loop;
 for i in 1..p_run loop collect_test('MULTISET_EXCEPT_ALL',      power(10, i),     power(10, i)); end loop;
 for i in 1..p_run loop collect_test('MULTISET_EXCEPT_ALL_DIST', power(10, p_run), power(10, i)); end loop;
 for i in 1..p_run loop collect_test('MULTISET_EXCEPT_DISTINCT',      power(10, i),     power(10, i)); end loop;
 for i in 1..p_run loop collect_test('MULTISET_EXCEPT_DISTINCT_DIST', power(10, p_run), power(10, i)); end loop;
 for i in 1..p_run loop collect_test('MULTISET_INTERSECT_ALL',      power(10, i),     power(10, i)); end loop;
 for i in 1..p_run loop collect_test('MULTISET_INTERSECT_ALL_DIST', power(10, p_run), power(10, i)); end loop;
 for i in 1..p_run loop collect_test('MULTISET_INTERSECT_DISTINCT',      power(10, i),     power(10, i)); end loop;
 for i in 1..p_run loop collect_test('MULTISET_INTERSECT_DISTINCT_DIST', power(10, p_run), power(10, i)); end loop;
end;
/ 

--exec multiset_test_run(3);

------------------------------- Test Control 2 ---------------------------------
create or replace procedure all_test_run_2(p_run number) as
begin
 collect_test_run(p_run);
 multiset_test_run(p_run);
end;
/ 

Performance of Oracle Object Collection Comparisons - Part1

Oracle object types are user-defined types that make it possible to model real-world entities, similar to the class mechanism in C++ and Java (Database Object-Relational Developer's Guide Performance of Object Comparisons).

This Blog presents an approach to investigate Performance of Oracle Object Collection Comparisons used in two functions:

    Converts a nested table into a set by eliminating duplicates. The function returns a nested table whose elements are distinct from one another. SET function requires map method, order method does NOT work.

    Two nested tables are equal if they have the same named type, have the same cardinality, and their elements are equal based on map method.

The next Blog:  Performance of Oracle Object Collection Comparisons - Part2 will talk about other two functions: COLLECT and Multiset Operators.

By implementing a map member function in Object (similar to Java Comparator/Comparable Interface), the number of calls can be recorded. In aid of such counter, this Blog is trying to find a way to study the complexity of applied algorithm (see appended test code).

1. Setup the test (see appended Test Code)

2. Run the test by:
    truncate table test_stat;
    exec all_test_run_1(4);

3. Wait test finished, query the statistics by:

SET LINES 400
SET NUMWIDTH 12
SET NUMFORMAT 999,999,999
COLUMN TOTAL_COMP_EST_RATIO FORMAT 999.99
select s.*, round(s.total_comp_est/nullif(s.total_comp, 0), 2) total_comp_est_ratio
  from (select t.*, round(10*1000*elapsed/nullif(total_comp, 0), 2) us_per_comp,
         case test_name 
           when 'SET_TEST'               then cnt*(cnt-1)
           when 'SET_TEST_DIST'          then cnt*(cnt-1)*(disticnt_cnt/cnt)
           when 'EQUAL_TEST'             then 2*cnt
           when 'EQUAL_TEST_DIST'        then 2*cnt
           when 'EQUAL_TEST_RANDOM'      then (cnt*disticnt_cnt/2)
           when 'EQUAL_TEST_DIST_RANDOM' then (cnt*disticnt_cnt/2)
         end total_comp_est 
     from test_stat t) s; 
returns:

TEST_NAME RUN_ID CNT DISTICNT_CNT ELAPSED TOTAL_COMP SINGLE_COMP US_PER_COMP TOTAL_COMP_EST TOTAL_COMP_EST_RATIO
SET_TEST
1
10
10
0
90
9
0
90
1
SET_TEST
2
100
100
2
9900
99
2.02
9900
1
SET_TEST
3
1000
1000
193
999000
999
1.93
999000
1
SET_TEST
4
10000
10000
18826
99990000
9999
1.88
99990000
1
SET_TEST_DIST
1
10000
10
21
109980
10.998
1.91
99990
0.91
SET_TEST_DIST
2
10000
100
198
1009800
100.98
1.96
999900
0.99
SET_TEST_DIST
3
10000
1000
1932
10008000
1000.8
1.93
9999000
1
SET_TEST_DIST
4
10000
10000
18802
99990000
9999
1.88
99990000
1
EQUAL_TEST
1
10
10
0
20
1
0
20
1
EQUAL_TEST
2
100
100
0
200
1
0
200
1
EQUAL_TEST
3
1000
1000
1
2000
1
5
2000
1
EQUAL_TEST
4
10000
10000
95
20000
1
47.5
20000
1
EQUAL_TEST_DIST
1
10000
10
95
20000
1
47.5
20000
1
EQUAL_TEST_DIST
2
10000
100
95
20000
1
47.5
20000
1
EQUAL_TEST_DIST
3
10000
1000
95
20000
1
47.5
20000
1
EQUAL_TEST_DIST
4
10000
10000
95
20000
1
47.5
20000
1
EQUAL_TEST_RANDOM
1
10
10
0
54
2.7
0
50
0.93
EQUAL_TEST_RANDOM
2
100
100
1
4710
23.55
2.12
5000
1.06
EQUAL_TEST_RANDOM
3
1000
1000
101
501358
250.679
2.01
500000
1
EQUAL_TEST_RANDOM
4
10000
10000
10142
50549260
2527.463
2.01
50000000
0.99
EQUAL_TEST_DIST_RANDOM
1
10000
10
327
1184932
59.2466
2.76
50000
0.04
EQUAL_TEST_DIST_RANDOM
2
10000
100
956
4374904
218.7452
2.19
500000
0.11
EQUAL_TEST_DIST_RANDOM
3
10000
1000
2968
14358672
717.9336
2.07
5000000
0.35
EQUAL_TEST_DIST_RANDOM
4
10000
10000
9992
49718366
2485.9183
2.01
50000000
1.01


The above test result table shows:

 SET_TEST has a total number of comparison equal to cnt*(cnt-1), that means a complexity of o(n²).
 SET_TEST_DIST has a total number of comparison equal to cnt*(cnt-1)*(disticnt_cnt/cnt), which depends the ratio of distinct items.
    Therefore elapsed time (in centisecond) increasing with number of distinct values.

 EQUAL_TEST has a total number of comparison equal to cnt*(cnt-1). i.e, a complexity of o(n).
 EQUAL_TEST_DIST has the same complexity as EQUAL_TEST, and elapsed time is irrelevant with number of distinct values.

 EQUAL_TEST_RANDOM has an estimated total number of comparison equal to (cnt*disticnt_cnt/2).
 EQUAL_TEST_DIST_RANDOM has the same estimated complexity as EQUAL_TEST_RANDOM.

TOTAL_COMP is the number of calls on map method (comparator). For each comparing of two objects, two calls are counted.

The estimated complexity (TOTAL_COMP_EST) is not precise and only an attempt to approximate the real complexity. It would be interesting to determine the exact form of computation in a long term.

The discussed performance behavior was first raised during 2010 FIFA World Cup, it takes a long way to be a bit clear.


Map and Order Method



Oracle Documentation: Basic Components of Oracle Objects said:
 A map method maps object return values to scalar values and can order multiple values by their position on the scalar axis. 
 
 An order method is a function for an object (SELF), with one declared parameter that is an object of the same type. 
 The method must return either a negative number, zero, or a positive number. 
 
 You can declare a map method or an order method but not both.
 
 When sorting or merging a large number of objects, use a map method, which maps all the objects into scalars, then sorts the scalars. 
 An order method is less efficient because it must be called repeatedly (it can compare only two objects at a time). 
The above test shows that the TOTAL_COMP (calls of map method) is not linear to the number of objects, which does not match the description:
 ... use a map method, which maps all the objects into scalars, then sorts the scalars.
It seems that map method is repeatedly called for each comparison of object instances.

Test Code




------------------------------- Setup map method ---------------------------------
drop table test_stat;

create table test_stat
 (test_name      varchar2 (40),
   run_id         number,
   cnt            number,
   disticnt_cnt   number,
   elapsed        number,
   total_comp     number,
   single_comp    number);
   
create or replace package helper as
 p_num1_cnt number := 0;
 procedure format(p_name varchar2, p_value number);
 procedure record(p_test_name varchar2, p_cnt number, p_disticnt_cnt number, 
                  p_elapsed number, p_total_comp number, p_single_comp number);
end helper;
/

create or replace package body helper as
 procedure format(p_name varchar2, p_value number) as
 begin
  dbms_output.put_line(rpad(p_name, 40) || lpad(p_value, 10));
 end format;

 procedure record(p_test_name varchar2, p_cnt number, p_disticnt_cnt number, 
                  p_elapsed number, p_total_comp number, p_single_comp number) as
   l_run_id  number;
 begin
   select nvl(max(run_id), 0) + 1 into l_run_id from test_stat where test_name = p_test_name;
   insert into test_stat values(p_test_name, l_run_id, p_cnt, p_disticnt_cnt
                 ,p_elapsed, p_total_comp, p_single_comp);
   commit;
 end record; 
end helper;
/

drop type tobj_tab force;
drop type tobj force;

create or replace type tobj as object (
 p_num1 number,
 p_num2 number,
 map member function comp return integer);
/

create or replace type body tobj as
 map member function comp return integer is 
    begin 
      helper.p_num1_cnt := helper.p_num1_cnt + 1;
      return p_num2; 
    end; 
end;
/

create or replace type tobj_tab as table of tobj;
/

------------------------------- SET_test ---------------------------------
create or replace procedure set_test (p_name varchar2, p_size number default 1000
                   ,p_dist_val pls_integer := null) as
 l_dist_val     number := coalesce(p_dist_val, p_size);
  l_tobj_tab          tobj_tab := tobj_tab();
  l_tobj_tab_distinct tobj_tab := tobj_tab();
  l_start_time     number;
  l_elapsed        number;
begin
  select cast(collect(tobj(level, mod(level, l_dist_val))) as tobj_tab) into l_tobj_tab 
    from dual connect by level <= p_size; 
    
  helper.p_num1_cnt := 0;
  l_start_time := dbms_utility.get_time;
  l_tobj_tab_distinct := set(l_tobj_tab);
  l_elapsed := dbms_utility.get_time - l_start_time;
  
  -- SET test depends on number of objects, and also number of distinct objects
  helper.record(p_name, cardinality(l_tobj_tab), l_tobj_tab_distinct.count,
         l_elapsed, helper.p_num1_cnt, (helper.p_num1_cnt/p_size));
  
  helper.format(rpad('-', 40, '-'), null);
  helper.format('l_tobj_tab.count=', cardinality(l_tobj_tab));
  helper.format('l_tobj_tab_distinct.count=', l_tobj_tab_distinct.count);
  helper.format('elapsed(centi)=', l_elapsed);
  helper.format('Total Number of Object Comparisons=', helper.p_num1_cnt);
  helper.format('Number of Object Comparisons / Object=', (helper.p_num1_cnt/p_size));
  helper.format('l_dist_val=', l_dist_val);
end;
/

--exec set_test('SET_TEST_DIST', 10, 5);

create or replace procedure set_test_run(p_run number) as
begin
 for i in 1..p_run loop
  set_test('SET_TEST', power(10, i), power(10, i));
 end loop;
 
 for i in 1..p_run loop
  set_test('SET_TEST_DIST', power(10, p_run), power(10, i));
 end loop;
end;
/ 

--exec set_test_run(3);

------------------------------- EQUAL_test ---------------------------------
create or replace procedure equal_test (p_name varchar2, p_size number default 1000
             ,p_dist_val pls_integer := null, p_random boolean :=false) as
 l_dist_val  number := coalesce(p_dist_val, p_size);
 l_test_name   varchar2(40);
  l_tobj_tab_1  tobj_tab := tobj_tab();
  l_tobj_tab_2 tobj_tab := tobj_tab();
  l_start_time  number;
  l_elapsed     number;
begin
  select cast(collect(tobj(level, mod(level, l_dist_val))) as tobj_tab) into l_tobj_tab_1 
    from dual connect by level <= p_size; 
 
  if p_random then
   l_test_name := p_name ||'_RANDOM';
  select cast(collect(tobj(x, mod(x, l_dist_val))) as tobj_tab) into l_tobj_tab_2 
     from (select level x from dual connect by level <= p_size order by dbms_random.value);   
 else
  l_test_name := p_name;
  select cast(collect(tobj(x, mod(x, l_dist_val))) as tobj_tab) into l_tobj_tab_2 
     from (select level x from dual connect by level <= p_size);   
 end if;
    
  helper.p_num1_cnt := 0;
  l_start_time := dbms_utility.get_time;
  if (l_tobj_tab_1 = l_tobj_tab_2) then
   helper.format('l_tobj_tab_1 = l_tobj_tab_2', null);
  else 
   helper.format('l_tobj_tab_1 != l_tobj_tab_2', null);
  end if;
  l_elapsed := dbms_utility.get_time - l_start_time;
  
  helper.record(l_test_name, cardinality(l_tobj_tab_1), l_dist_val,
         l_elapsed, helper.p_num1_cnt, (helper.p_num1_cnt/p_size/2));
         
  helper.format('l_tobj_tab_1.count=', cardinality(l_tobj_tab_1));
  helper.format('l_tobj_tab_2.count=', l_tobj_tab_2.count);
  helper.format('elapsed(centi)=', l_elapsed);
  helper.format('Total Number of Object Comparisons=', helper.p_num1_cnt);
  helper.format('Number of Object Comparisons/Object=', (helper.p_num1_cnt/p_size/2));
  helper.format('l_dist_val=', l_dist_val);
end;
/

--exec equal_test(10, 5, false);
--exec equal_test(10, 5, true);

create or replace procedure equal_test_run(p_run number, p_random boolean :=false) as
begin
 for i in 1..p_run loop
  equal_test('EQUAL_TEST', power(10, i), power(10, i), p_random);
 end loop;
 
 for i in 1..p_run loop
  equal_test('EQUAL_TEST_DIST', power(10, p_run), power(10, i), p_random);
 end loop;
end;
/ 

--exec equal_test_run(3, false);
--exec equal_test_run(3, true);

------------------------------- Test Control 1 ---------------------------------
create or replace procedure all_test_run_1(p_run number, p_random boolean :=false) as
begin
 set_test_run(p_run);
 equal_test_run(p_run, false);
 equal_test_run(p_run, true);
end;
/