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.
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>
[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
Got a call asking me to provide advice on the cause of ORA-3180 error on an Active Data Guard standby database instance:
SQL> explain plan for select * from dual;
explain plan for select * from dual
*
ERROR at line 1:
ORA-00604: error occurred at recursive SQL level 1
ORA-03180: Sequence values cannot be allocated for Oracle Active Data Guard standby.
It is a documented fact that sequences can be used within an Oracle Active Data Guard physical standby database: Using Sequences in Oracle Active Data Guard.
I have not found whether the algorithm used to identify the primary database is documented either on MOS or in the documentation.
I have been tinkering around with the issue for a while, so this blog post is about my findings.
First, the most useful source of information about this error is the server process trace file. Here is an excerpt from it:
I was curious about what "by reverse lookup" meant. I speculate that it means that the primary database TNS alias (or the fully-formed TNS descriptor) is obtained from one of LOG_ARCHIVE_DEST_n parameters (let it call LADn for the sake of shortness).
And conversely, there is a forward lookup by the FAL_SERVER parameter:
krsd_get_primary_connect_string: found pcs 'adg1' by FAL_SERVER lookup
Connected to primary database target adg1
krsd_get_primary_connect_string: found pcs 'adg1' by FAL_SERVER lookup
Connected to primary database target adg1
It seems that Oracle is considering either the LADn or FAL_SERVER parameter when it tries to identify the primary database connect identifier to request a sequence cache.
I have done several tests in my sandbox Data Guard environment and I think that the LADn take precedence over the FAL_SERVER.
All of the tests were performed on the following Data Guard configuration:
I ran my scripts in adg2, which is a physical standby database, and the databases have DBBP 12.1.0.2.161018 applied.
Here is what I was observing while doing my experiments: 1. the first LADn with db_unique_name=<primary_db> is selected. The corresponding LOG_ARCHIVE_DEST_STATE_N, VALID_FOR parameters are ignored.
Here is an example where I set VALID_FOR=(ALL_LOGFILES,STANDBY_ROLE), LOG_ARCHIVE_DEST_STATE_4=DEFER and, still, the LADn was used to identify the primary database TNS:
SQL> alter system set fal_server='adg1' log_archive_dest_4='service=non_existent valid_for=(all_logfiles,standby_role) db_unique_name=adg1' log_archive_dest_state_4=defer;
System altered.
SQL> conn / as sysdba
Connected.
SQL> explain plan for select * from dual;
explain plan for select * from dual
*
ERROR at line 1:
ORA-00604: error occurred at recursive SQL level 1
ORA-03180: Sequence values cannot be allocated for Oracle Active Data Guard standby.
-- trace file
krsd_get_primary_connect_string: found pcs 'non_existent' by reverse lookup
OCIServerAttach failed -1
.. Detailed OCI error val is 12154 and errmsg is 'ORA-12154: TNS:could not resolve the connect identifier specified
'
OCIServerAttach failed -1
.. Detailed OCI error val is 12154 and errmsg is 'ORA-12154: TNS:could not resolve the connect identifier specified
'
OCIServerAttach failed -1
.. Detailed OCI error val is 12154 and errmsg is 'ORA-12154: TNS:could not resolve the connect identifier specified
'
OCIServerAttach failed -1
.. Detailed OCI error val is 12154 and errmsg is 'ORA-12154: TNS:could not resolve the connect identifier specified
'
*** 2017-02-09 14:05:22.153950 4929 krsh.c
Error 12154 received logging on to the standby
*** 2017-02-09 14:05:22.153969 1460 krsu.c
krsu_rmi_lwc_connect: Encountered error status 12154 attempting connection to non_existent
non_existent: Encountered connect exception 12154
2. when there is no LADn with db_unique_name=<primary_db> is present then the FAL_SERVER parameter is used. It is sequentially traversed left-to-right:
SQL> alter system set fal_server='x','adg1','y';
System altered.
SQL> explain plan for select * from dual;
Explained.
-- trace file
*** 2017-02-09 14:42:50.944
*** SESSION ID:(47.31048) 2017-02-09 14:42:50.944
*** CLIENT ID:() 2017-02-09 14:42:50.944
*** SERVICE NAME:(SYS$USERS) 2017-02-09 14:42:50.944
*** MODULE NAME:(sqlplus@userhost (TNS V1-V3)) 2017-02-09 14:42:50.944
*** CLIENT DRIVER:(SQL*PLUS) 2017-02-09 14:42:50.944
*** ACTION NAME:() 2017-02-09 14:42:50.944
OCIServerAttach failed -1
.. Detailed OCI error val is 12154 and errmsg is 'ORA-12154: TNS:could not resolve the connect identifier specified
'
OCIServerAttach failed -1
.. Detailed OCI error val is 12154 and errmsg is 'ORA-12154: TNS:could not resolve the connect identifier specified
'
OCIServerAttach failed -1
.. Detailed OCI error val is 12154 and errmsg is 'ORA-12154: TNS:could not resolve the connect identifier specified
'
OCIServerAttach failed -1
.. Detailed OCI error val is 12154 and errmsg is 'ORA-12154: TNS:could not resolve the connect identifier specified
'
*** 2017-02-09 14:42:50.960591 4929 krsh.c
Error 12154 received logging on to the standby
*** 2017-02-09 14:42:50.960676 4929 krsh.c
FAL[client, USER]: Error 12154 connecting to x for fetching gap sequence
ORA-12154: TNS:could not resolve the connect identifier specified
krsd_get_primary_connect_string: found pcs 'adg1' by FAL_SERVER lookup
Connected to primary database target adg1
OCIServerAttach failed -1
.. Detailed OCI error val is 12154 and errmsg is 'ORA-12154: TNS:could not resolve the connect identifier specified
'
OCIServerAttach failed -1
.. Detailed OCI error val is 12154 and errmsg is 'ORA-12154: TNS:could not resolve the connect identifier specified
'
OCIServerAttach failed -1
.. Detailed OCI error val is 12154 and errmsg is 'ORA-12154: TNS:could not resolve the connect identifier specified
'
OCIServerAttach failed -1
.. Detailed OCI error val is 12154 and errmsg is 'ORA-12154: TNS:could not resolve the connect identifier specified
'
*** 2017-02-09 14:42:51.071116 4929 krsh.c
Error 12154 received logging on to the standby
*** 2017-02-09 14:42:51.071188 4929 krsh.c
FAL[client, USER]: Error 12154 connecting to x for fetching gap sequence
ORA-12154: TNS:could not resolve the connect identifier specified
krsd_get_primary_connect_string: found pcs 'adg1' by FAL_SERVER lookup
Connected to primary database target adg1
How could one come across this issue:
1. Have incorrect parameter settings and do not use Data Guard Broker. That is what the problem was when my client came upon it.
2. Actually, we can face this issue using Data Guard Broker. Data Guard Broker does not change the FAL_SERVER parameters on switchover, at least, it is how it is working now. See, for example, this link.
One possible workaround - it is to manually invoke the DGMGRL "enable configuration" command each time when the switchover takes place. I raised a SR with Oracle about this problem but I decided not to progress towards the permanent solution.
I have recently discovered a case when DBMS_METADATA.GET_SXML_DDL returns incorrect DDL for the trigger in an EBR environment.
Here is a test case to reproduce the issue that is present in 12.1.0.2.170117 and 11.2.0.4.161018:
SQL> grant connect, create table, create view, create trigger to tc identified by tc;
Grant succeeded.
SQL>
SQL> alter user tc enable editions for view,trigger;
User altered.
SQL>
SQL> conn tc/tc
Connected.
SQL>
SQL> create table t (
2 x int)
3 /
Table created.
SQL>
SQL> create or replace editioning view ev
2 as
3 select *
4 from t
5 /
View created.
SQL>
SQL> create or replace trigger trg
2 before update of x on ev
3 declare
4 begin
5 null;
6 end;
7 /
Trigger created.
Let us look at the DDL of the trigger returning by DBMS_METADATA.GET_DDL and DBMS_METADATA.GET_SXML_DDL functions.
SQL> select dbms_metadata.get_ddl( 'TRIGGER', 'TRG') from dual;
DBMS_METADATA.GET_DDL('TRIGGER','TRG')
--------------------------------------------------------------------------------
CREATE OR REPLACE EDITIONABLE TRIGGER "TC"."TRG"
before update of x on ev
declare
begin
null;
end;
ALTER TRIGGER "TC"."TRG" ENABLE
SQL> select dbms_metadata.get_sxml_ddl( 'TRIGGER', 'TRG') from dual;
DBMS_METADATA.GET_SXML_DDL('TRIGGER','TRG')
--------------------------------------------------------------------------------
CREATE OR REPLACE TRIGGER "TC"."TRG"
BEFORE UPDATE OF X ON "TC"."EV"
declare
begin
null;
end;
They are pretty much the same. Now I change the status of my trigger. Please note the highlighted lines showing the differences:
SQL> alter trigger trg enable;
Trigger altered.
SQL>
SQL> select dbms_metadata.get_ddl( 'TRIGGER', 'TRG') from dual;
DBMS_METADATA.GET_DDL('TRIGGER','TRG')
--------------------------------------------------------------------------------
CREATE OR REPLACE EDITIONABLE TRIGGER "TC"."TRG"
before update of x on ev
declare
begin
null;
end;
ALTER TRIGGER "TC"."TRG" ENABLE
SQL> select dbms_metadata.get_sxml_ddl( 'TRIGGER', 'TRG') from dual;
DBMS_METADATA.GET_SXML_DDL('TRIGGER','TRG')
--------------------------------------------------------------------------------
CREATE OR REPLACE TRIGGER "TC"."TRG"
BEFORE UPDATE OF X, X ON "TC"."EV"
declare
begin
null;
end;
I have ended up with two X columns in the output of DBMS_METADATA.GET_SXML_DDL, which is, in fact, a non-working DDL statement.
I played more with this issue and I have eventually obtained four X columns and it is not a limit:
SQL> alter trigger trg disable;
Trigger altered.
SQL>
SQL> select dbms_metadata.get_ddl( 'TRIGGER', 'TRG') from dual;
DBMS_METADATA.GET_DDL('TRIGGER','TRG')
--------------------------------------------------------------------------------
CREATE OR REPLACE EDITIONABLE TRIGGER "TC"."TRG"
before update of x on ev
declare
begin
null;
end;
ALTER TRIGGER "TC"."TRG" DISABLE
SQL> select dbms_metadata.get_sxml_ddl( 'TRIGGER', 'TRG') from dual;
DBMS_METADATA.GET_SXML_DDL('TRIGGER','TRG')
--------------------------------------------------------------------------------
CREATE OR REPLACE TRIGGER "TC"."TRG"
BEFORE UPDATE OF X, X, X ON "TC"."EV"
declare
begin
null;
end;
ALTER TRIGGER "TC"."TRG" DISABLE
SQL>
SQL> alter trigger trg enable;
Trigger altered.
SQL>
SQL> select dbms_metadata.get_ddl( 'TRIGGER', 'TRG') from dual;
DBMS_METADATA.GET_DDL('TRIGGER','TRG')
--------------------------------------------------------------------------------
CREATE OR REPLACE EDITIONABLE TRIGGER "TC"."TRG"
before update of x on ev
declare
begin
null;
end;
ALTER TRIGGER "TC"."TRG" ENABLE
SQL> select dbms_metadata.get_sxml_ddl( 'TRIGGER', 'TRG') from dual;
DBMS_METADATA.GET_SXML_DDL('TRIGGER','TRG')
--------------------------------------------------------------------------------
CREATE OR REPLACE TRIGGER "TC"."TRG"
BEFORE UPDATE OF X, X, X, X ON "TC"."EV"
declare
begin
null;
end;
The DBMS_METADATA.GET_SXML_DDL procedure uses a SELECT statement similar to the above to obtain the DDL:
SELECT /*+all_rows*/
SYS_XMLGEN(
VALUE(KU$),
XMLFORMAT.createFormat2('TRIGGER_T', '7')),
KU$.OBJ_NUM
FROM SYS.KU$_TRIGGER_VIEW KU$
WHERE NOT (KU$.BASE_OBJ IS NOT NULL AND BITAND(KU$.BASE_OBJ.FLAGS,128)!=0)
AND KU$.SCHEMA_OBJ.NAME = 'TRG'
AND KU$.SCHEMA_OBJ.OWNER_NAME = 'TC';
The column list for the trigger comes from this part of the SYS.KU$_TRIGGER_VIEW view:
cast(multiset(select * from ku$_triggercol_view tv
where tv.obj_num=t.obj#
) as ku$_triggercol_list_t
),
The code of the KU$_TRIGGERCOL_VIEW view is:
CREATE OR REPLACE FORCE NONEDITIONABLE VIEW "SYS"."KU$_TRIGGERCOL_VIEW" OF "SYS"."KU$_TRIGGERCOL_T"
WITH OBJECT IDENTIFIER (obj_num,intcol_num,type_num) AS
select '1','0',
tc.obj#, tc.col#, tc.type#, tc.position#, tc.intcol#, c.name,
(select a.name from attrcol$ a where
a.obj#=tc.obj# and a.intcol#=tc.intcol#)
from col$ c, triggercol$ tc, trigger$ t
where tc.obj#=t.obj#
and c.obj#=t.baseobject
and c.intcol#=tc.intcol#
And the final part of the puzzle is the TRIGGERCOL$ table:
SQL> select * from sys.triggercol$ where obj#=(select object_id from dba_objects where owner='TC' and object_name='TRG');
OBJ# COL# TYPE# POSITION# INTCOL#
---------- ---------- ---------- ---------- ----------
214352 1 0 0 1
214352 1 0 0 1
214352 1 0 0 1
214352 1 0 0 1
214352 1 1024 0 1
It gets one row each time I execute the "ALTER TRIGGER ENABLE/DISABLE" statement. I think Oracle Developers should filter the rows because there is only one row with TYPE#=1024.
DBMS_METADATA.GET_DDL returns correct DDL and it seems to be come from the DDL passed by a user.
Conversely, DBMS_METADATA.GET_SXML_DDL tries to reconstruct the user's DDL and it messes things up.
Since I had added ENABLEMONITORING in the GLOBALS file, I noticed that $OGG_HOME/dirbdb directory started growing.
That was OGG version 12.2.0.1.160517.
The size of this directory was 23G in the test environment and the ENABLEMONITORING option was set 3 weeks ago:
-bash-4.1$ du -sh dirbdb
23.8G dirbdb
From that 23.8G , 23.5G was occupied by the log.* files like below:
-rw-r----- 1 oracle dba 10485760 Nov 16 18:16 log.0000015971
-rw-r----- 1 oracle dba 10485760 Nov 16 18:28 log.0000015972
-rw-r----- 1 oracle dba 10485760 Nov 16 18:41 log.0000015973
-rw-r----- 1 oracle dba 10485760 Nov 16 18:55 log.0000015974
-rw-r----- 1 oracle dba 10485760 Nov 16 19:08 log.0000015975
-rw-r----- 1 oracle dba 10485760 Nov 16 19:20 log.0000015976
-rw-r----- 1 oracle dba 10485760 Nov 16 19:32 log.0000015977
-rw-r----- 1 oracle dba 10485760 Nov 16 19:43 log.0000015978
-rw-r----- 1 oracle dba 10485760 Nov 16 19:55 log.0000015979
-rw-r----- 1 oracle dba 10485760 Nov 16 20:07 log.0000015980
-rw-r----- 1 oracle dba 10485760 Nov 16 20:19 log.0000015981
-rw-r----- 1 oracle dba 10485760 Nov 16 20:31 log.0000015982
These files were generated approximately every ten minutes and each of them was 10M in size that made up 1.4G daily.
Having searched through MOS and Internet search engines, I stumbled across this MOSC Thread: Monitoring - Berkeley Database.
So I created a new DB_CONFIG file within the dirbdb directory and put this line into it:
Then I restarted my OGG processes and discovered that these log files were gone.
Now there are only two log files that are kept:
[oracle@host ggs]$ ls -ltr dirbdb/log*
-rw-r----- 1 oracle dba 10485760 Nov 28 13:31 dirbdb/log.0000017532
-rw-r----- 1 oracle dba 10485760 Nov 28 13:41 dirbdb/log.0000017533
[oracle@host ggs]$ ls -ltr dirbdb/log*
-rw-r----- 1 oracle dba 10485760 Nov 28 13:42 dirbdb/log.0000017533
-rw-r----- 1 oracle dba 10485760 Nov 28 13:51 dirbdb/log.0000017534
[oracle@host ggs]$ ls -ltr dirbdb/log*
-rw-r----- 1 oracle dba 10485760 Nov 29 07:21 dirbdb/log.0000017625
-rw-r----- 1 oracle dba 10485760 Nov 29 07:22 dirbdb/log.0000017626
Looks like another option that should be added in the environments in which ENABLEMONITORING is set.
Yet, MOS returns no hits apart from the aforementioned MOSC thread.
A couple of months ago I had to configure OGG IE (Oracle GoldenGate Integrated Extract) to exclude specific DDL from replication.
Having worked a lot with Oracle Streams, I decided to utilize DBMS_STREAMS_ADM.SET_TAG for that task.
I found a relevant MOS document How to exclude ddl in IE (integrated extract) issued from a specific user? (Doc ID 2107293.1) pretty fast.
The document suggested putting TRANLOGOPTIONS EXCLUDETAG into an extract parameter file and than all DDL statements preceeding with DBMS_STREAMS_SET.TAG should not be replicated.
Unfortunately the provided solution did not work for me.
I used OGG Server 12.2.0.1.160823 on Linux x86-64 (which means that I applied the latest bundle patch available at the moment).
The issue can be easily reproduced.
The database version used in this test was 12.1.0.2.160719.
Here are my extract and replicat parameter files:
GGSCI (misha2 as tc_ogg_replicat@db2) 112> view params etag
EXTRACT ETAG
USERIDALIAS db1_tc_ogg_extract
TRANLOGOPTIONS EXCLUDETAG 34
LOGALLSUPCOLS
EXTTRAIL ./dirdat/tc
DDL INCLUDE ALL
TABLE TC.*;
GGSCI (misha2 as tc_ogg_replicat@db2) 113> view params rtag
REPLICAT RTAG
USERIDALIAS db2_tc_ogg_replicat
MAP TC.*, TARGET TC.*;
Test schema TC will be used for demonstration and I setup the extract to exclude any LCRs with tag 34.
Then I am going to create and start the OGG processes with the following script:
GGSCI (misha2 as tc_ogg_replicat@db2) 138> alter credentialstore add user tc_ogg_extract@db1 password tc_ogg_extract alias db1_tc_ogg_extract
Credential store in ./dircrd/ altered.
GGSCI (misha2 as tc_ogg_replicat@db2) 139> alter credentialstore add user tc_ogg_replicat@db2 password tc_ogg_replicat alias db2_tc_ogg_replicat
Credential store in ./dircrd/ altered.
GGSCI (misha2 as tc_ogg_replicat@db2) 140>
GGSCI (misha2 as tc_ogg_replicat@db2) 140> dblogin useridalias db1_tc_ogg_extract
Successfully logged into database.
GGSCI (misha2 as tc_ogg_extract@db1) 141> add extract etag integrated tranlog begin now
EXTRACT (Integrated) added.
GGSCI (misha2 as tc_ogg_extract@db1) 142> add exttrail ./dirdat/tc extract etag
EXTTRAIL added.
GGSCI (misha2 as tc_ogg_extract@db1) 143> register extract etag database
2016-10-31 12:46:49 INFO OGG-02003 Extract ETAG successfully registered with database at SCN 39029510.
GGSCI (misha2 as tc_ogg_extract@db1) 144>
GGSCI (misha2 as tc_ogg_extract@db1) 146> dblogin useridalias db2_tc_ogg_replicat
Successfully logged into database.
GGSCI (misha2 as tc_ogg_replicat@db2) 147> add replicat rtag , integrated, exttrail ./dirdat/tc
REPLICAT (Integrated) added.
GGSCI (misha2 as tc_ogg_replicat@db2) 148> start extract etag
Sending START request to MANAGER ...
EXTRACT ETAG starting
GGSCI (misha2 as tc_ogg_replicat@db2) 149> start replicat rtag
Sending START request to MANAGER ...
REPLICAT RTAG starting
I used two databases in my setup - db1 and db2 that I named SOURCE and TARGET in the rest of this blog post for the sake of clarity.
The extract configured to capture the changes from db1 database and write data to trail files.
The replicat reads the trail files and applies the changes into db2 database.
Next I am about to run the following code in the source database from which the extract captures changes:
Havind done that, I got next results in SOURCE database:
TC@SOURCE> select * from t;
ID MSG
---------- ----------
1 NO TAG
2 TAG 12
3 TAG 34
4 TAG 56
And that in TARGET:
TC@TARGET> select * from t order by id;
ID MSG
---------- ----------
1 NO TAG
2 TAG 12
4 TAG 56
Notice that an insert of a record with ID=3, MSG="TAG 34" was not replicated because we have filtered out that record on the extract.
That works flawlessly being executed for DML, but it does not work for DDL:
TC@SOURCE> exec dbms_streams_adm.set_tag( hextoraw('12'))
PL/SQL procedure successfully completed.
TC@SOURCE>
TC@SOURCE> alter table t add tag12 int;
Table altered.
TC@SOURCE>
TC@SOURCE> exec dbms_streams_adm.set_tag( hextoraw('34'))
PL/SQL procedure successfully completed.
TC@SOURCE>
TC@SOURCE> alter table t add tag34 int;
Table altered.
TC@SOURCE> describe t
Name Null? Type
----------------------------------------- -------- ----------------------------
ID NUMBER(38)
MSG VARCHAR2(10)
TAG12 NUMBER(38)
TAG34 NUMBER(38)
I have added two columns to the table and the second one, TAG34, should not have been replicated.
But in fact, both of the commands were replicated:
TC@TARGET> describe t
Name Null? Type
----------------------------------------- -------- ----------------------------
ID NUMBER(38)
MSG VARCHAR2(10)
TAG12 NUMBER(38)
TAG34 NUMBER(38)
GGSCI (misha2 as tc_ogg_replicat@db2) 168> view params etag
EXTRACT ETAG
USERIDALIAS db1_tc_ogg_extract
TRANLOGOPTIONS EXCLUDETAG 34
TRANLOGOPTIONS _dbfilterddl
LOGALLSUPCOLS
EXTTRAIL ./dirdat/tc
DDL INCLUDE ALL
TABLE TC.*;
Having added that, the same code adding two columns worked as it should:
TC@SOURCE> describe t
Name Null? Type
----------------------------------------- -------- ----------------------------
ID NUMBER(38)
MSG VARCHAR2(10)
TAG12 NUMBER(38)
TAG34 NUMBER(38)
TC@TARGET> describe t
Name Null? Type
----------------------------------------- -------- ----------------------------
ID NUMBER(38)
MSG VARCHAR2(10)
TAG12 NUMBER(38)
It means that TAG34 column, being added with tag 34, was not replicated.
There is also a new line in a ggserr.log file that was not present when I started the extract without _dbfilterddl:
Logmining server DDL filtering enabled.
2016-10-31 13:54:33 INFO OGG-00963 Oracle GoldenGate Manager for Oracle, mgr.prm: Command received from GGSCI on host [172.16.113.245]:57437 (START EXTRACT ETAG ).
2016-10-31 13:54:33 INFO OGG-00960 Oracle GoldenGate Manager for Oracle, mgr.prm: Access granted (rule #6).
2016-10-31 13:54:34 INFO OGG-00992 Oracle GoldenGate Capture for Oracle, etag.prm: EXTRACT ETAG starting.
2016-10-31 13:54:34 INFO OGG-03059 Oracle GoldenGate Capture for Oracle, etag.prm: Operating system character set identified as UTF-8.
2016-10-31 13:54:34 INFO OGG-02695 Oracle GoldenGate Capture for Oracle, etag.prm: ANSI SQL parameter syntax is used for parameter parsing.
2016-10-31 13:54:38 INFO OGG-03522 Oracle GoldenGate Capture for Oracle, etag.prm: Setting session time zone to source database time zone 'GMT'.
2016-10-31 13:54:38 WARNING OGG-04033 Oracle GoldenGate Capture for Oracle, etag.prm: LOGALLSUPCOLS has set the NOCOMPRESSDELETES and GETUPDATEBEFORES parameters on.
2016-10-31 13:54:38 INFO OGG-01815 Oracle GoldenGate Capture for Oracle, etag.prm: Virtual Memory Facilities for: BR
anon alloc: mmap(MAP_ANON) anon free: munmap
file alloc: mmap(MAP_SHARED) file free: munmap
target directories:
/u01/app/oracle/12.2.0.1/ggs/BR/ETAG.
2016-10-31 13:54:38 INFO OGG-01851 Oracle GoldenGate Capture for Oracle, etag.prm: filecaching started: thread ID: 140594853938944.
2016-10-31 13:54:38 INFO OGG-00975 Oracle GoldenGate Manager for Oracle, mgr.prm: EXTRACT ETAG starting.
2016-10-31 13:54:38 INFO OGG-01815 Oracle GoldenGate Capture for Oracle, etag.prm: Virtual Memory Facilities for: COM
anon alloc: mmap(MAP_ANON) anon free: munmap
file alloc: mmap(MAP_SHARED) file free: munmap
target directories:
/u01/app/oracle/12.2.0.1/ggs/dirtmp.
2016-10-31 13:54:58 WARNING OGG-02045 Oracle GoldenGate Capture for Oracle, etag.prm: Database does not have streams_pool_size initialization parameter configured.
2016-10-31 13:54:59 INFO OGG-02248 Oracle GoldenGate Capture for Oracle, etag.prm: Logmining server DDL filtering enabled.
2016-10-31 13:55:08 INFO OGG-02068 Oracle GoldenGate Capture for Oracle, etag.prm: Integrated capture successfully attached to logmining server OGG$CAP_ETAG using OGGCapture API.
2016-10-31 13:55:08 INFO OGG-02089 Oracle GoldenGate Capture for Oracle, etag.prm: Source redo compatibility version is: 12.1.0.2.0.
2016-10-31 13:55:08 INFO OGG-02086 Oracle GoldenGate Capture for Oracle, etag.prm: Integrated Dictionary will be used.
2016-10-31 13:55:09 WARNING OGG-02905 Oracle GoldenGate Capture for Oracle, etag.prm: Replication of OID column in object tables may diverge.
2016-10-31 13:55:09 INFO OGG-00993 Oracle GoldenGate Capture for Oracle, etag.prm: EXTRACT ETAG started.
tl;dr
EXCLUDETAG parameter does not work when a tag is set using DBMS_STREAMS_ADM.SET_TAG in OGG 12.2.0.1.160823 . It prevents replicating only DML commands and does not restrict DDL commands from being replicated.
We could use underscope parameter _dbfilterddl in the extract parameter file like in the following line:
TRANLOGOPTIONS _dbfilterddl
This way we may restrict both DDL and DML commands from being replicated when the appropriate tag is set (or any in case we use "EXCLUDETAG +" in the extract parameter file).
Today I have faced an interesting issue performing GoldenGate initial-load with a Direct Bulk Load to SQL*Loader.
The issue was related to incorrect handling of unused columns during such loads and can cause incorrect data getting loaded into a database under certain conditions.
I tried to reproduce the issue using one database in my setup but wasn't able to do that and stuck with two databases.
I used Oracle Database 12.1.0.2 with DBBP 12.1.0.2.160419 applied and GoldenGate 12.2.0.1.160419 Patch Set.
I'm going to use two database in my test case, let it be SOURCE and TARGET. Firstly, let's create a test schema with a single table populating it with some data:
Consider the scenario when we have decided to resynchronize data in TARGET database from SOURCE database.
I'm going to remove all rows from the table in TARGET database first:
Proceed with GoldenGate setup. I want to use GoldenGate Direct Bulk Load to SQL*Loader capability to move the data from SOURCE database to TARGET database.
Let's use IRTC - as a name of the initial load replicat and IETC - as a name of the initial load extract:
-- setup initial load replicat
GGSCI (ogg-test) 2> edit params irtc
-- UserIdAlias may be customized accordingly to your environment or simply use a username/password pair
Replicat irtc
AssumeTargetDefs
UserIdAlias target_ogg_replicat
DiscardFile ./dirrpt/irtc.dsc, Purge
-- I want to use Direct Bulk Load
BulkLoad
-- I used PDB "orcl" for my experiments:
Map orcl.tc.*, target orcl.tc.*;
-- setup initial load extract
GGSCI (ogg-test) 149> edit params ietc
Extract ietc
RmtHost ogg-test, MgrPort 7809
RmtTask Replicat, Group irtc
UserIdAlias source_ogg_extract
Table orcl.tc.direct_load;
-- let's create GoldenGate processes
GGSCI (ogg-test) 116> add replicat irtc SpecialRun
REPLICAT added.
GGSCI (ogg-test) 117> add extract ietc SourceIsTable
EXTRACT added.
The setup has been finished. Right now we can try to perform initial load:
GGSCI (ogg-test) 15> info i*tc, tasks
EXTRACT IETC Initialized 2016-09-01 08:54 Status STOPPED
Checkpoint Lag Not Available
Log Read Checkpoint Not Available
First Record Record 0
Task SOURCEISTABLE
REPLICAT IRTC Initialized 2016-09-01 08:54 Status STOPPED
Checkpoint Lag 00:00:00 (updated 00:00:28 ago)
Log Read Checkpoint Not Available
Task SPECIALRUN
GGSCI (ogg-test) 16> start extract ietc
Sending START request to MANAGER ...
EXTRACT IETC starting
The load has completed pretty soon:
GGSCI (ogg-test) 17> info i*tc, tasks
EXTRACT IETC Last Started 2016-09-01 08:55 Status STOPPED
Checkpoint Lag Not Available
Log Read Checkpoint Table ORCL.TC.DIRECT_LOAD
2016-09-01 08:55:27 Record 1
Task SOURCEISTABLE
REPLICAT IRTC Initialized 2016-09-01 08:54 Status STOPPED
Checkpoint Lag 00:00:00 (updated 00:02:09 ago)
Log Read Checkpoint Not Available
Task SPECIALRUN
ggserr.log file doesn't raise any concerns:
2016-09-01 08:55:11 INFO OGG-00987 Oracle GoldenGate Command Interpreter for Oracle: GGSCI command (velikikh): start extract ietc.
2016-09-01 08:55:11 INFO OGG-00963 Oracle GoldenGate Manager for Oracle, mgr.prm: Command received from GGSCI on host [127.0.0.1]:54562 (START EXTRACT IETC ).
2016-09-01 08:55:11 INFO OGG-00960 Oracle GoldenGate Manager for Oracle, mgr.prm: Access granted (rule #8).
2016-09-01 08:55:11 INFO OGG-01017 Oracle GoldenGate Capture for Oracle, ietc.prm: Wildcard resolution set to IMMEDIATE because SOURCEISTABLE is used.
2016-09-01 08:55:11 INFO OGG-00992 Oracle GoldenGate Capture for Oracle, ietc.prm: EXTRACT IETC starting.
2016-09-01 08:55:11 INFO OGG-03059 Oracle GoldenGate Capture for Oracle, ietc.prm: Operating system character set identified as ISO-8859-1.
2016-09-01 08:55:11 INFO OGG-02695 Oracle GoldenGate Capture for Oracle, ietc.prm: ANSI SQL parameter syntax is used for parameter parsing.
2016-09-01 08:55:12 INFO OGG-03522 Oracle GoldenGate Capture for Oracle, ietc.prm: Setting session time zone to source database time zone 'GMT'.
2016-09-01 08:55:12 WARNING OGG-00752 Oracle GoldenGate Capture for Oracle, ietc.prm: Failed to validate table ORCL.TC.DIRECT_LOAD. Likely due to existence of unused column. Please make sure you use sourcedefs in downstream Replicat, or the target table has exactly the same unused columns when using ASSUMETARGETDEFS or DDL replication.
2016-09-01 08:55:12 WARNING OGG-06439 Oracle GoldenGate Capture for Oracle, ietc.prm: No unique key is defined for table DIRECT_LOAD. All viable columns will be used to represent the key, but may not guarantee uniqueness. KEYCOLS may be used to define the key.
2016-09-01 08:55:12 INFO OGG-06509 Oracle GoldenGate Capture for Oracle, ietc.prm: Using the following key columns for source table ORCL.TC.DIRECT_LOAD: COLUMN1, COLUMN2, COLUMN3.
2016-09-01 08:55:12 INFO OGG-01851 Oracle GoldenGate Capture for Oracle, ietc.prm: filecaching started: thread ID: 7.
2016-09-01 08:55:12 INFO OGG-01815 Oracle GoldenGate Capture for Oracle, ietc.prm: Virtual Memory Facilities for: COM
anon alloc: mmap(MAP_ANON) anon free: munmap
file alloc: mmap(MAP_SHARED) file free: munmap
target directories:
/export/home/velikikh/oracle/12.2.0.1/ggs/dirtmp.
2016-09-01 08:55:16 INFO OGG-00975 Oracle GoldenGate Manager for Oracle, mgr.prm: EXTRACT IETC starting.
2016-09-01 08:55:16 INFO OGG-00993 Oracle GoldenGate Capture for Oracle, ietc.prm: EXTRACT IETC started.
2016-09-01 08:55:16 INFO OGG-00963 Oracle GoldenGate Manager for Oracle, mgr.prm: Command received from EXTRACT on host [127.0.0.1]:58728 (START REPLICAT IRTC CPU -1 PRI -1 PARAMS ).
2016-09-01 08:55:16 INFO OGG-00960 Oracle GoldenGate Manager for Oracle, mgr.prm: Access granted (rule #8).
2016-09-01 08:55:16 INFO OGG-01025 Oracle GoldenGate Delivery for Oracle: REPLICAT task started by manager (port 7810).
2016-09-01 08:55:21 INFO OGG-00963 Oracle GoldenGate Manager for Oracle, mgr.prm: Command received from RMTTASK on host [::1]:59974 (REPORT 3871 7810).
2016-09-01 08:55:21 INFO OGG-00960 Oracle GoldenGate Manager for Oracle, mgr.prm: Access granted (rule #1).
2016-09-01 08:55:21 INFO OGG-00973 Oracle GoldenGate Manager for Oracle, mgr.prm: Manager started replicat task process (Port 7810).
2016-09-01 08:55:26 INFO OGG-01229 Oracle GoldenGate Delivery for Oracle: Connected to ogg-test:50783.
2016-09-01 08:55:26 INFO OGG-00995 Oracle GoldenGate Delivery for Oracle, irtc.prm: REPLICAT IRTC starting.
2016-09-01 08:55:26 INFO OGG-03059 Oracle GoldenGate Delivery for Oracle, irtc.prm: Operating system character set identified as ISO-8859-1.
2016-09-01 08:55:26 INFO OGG-02695 Oracle GoldenGate Delivery for Oracle, irtc.prm: ANSI SQL parameter syntax is used for parameter parsing.
2016-09-01 08:55:27 INFO OGG-02679 Oracle GoldenGate Delivery for Oracle, irtc.prm: The Replicat process logged on to database ORCL and can only apply to that database.
2016-09-01 08:55:27 INFO OGG-06451 Oracle GoldenGate Delivery for Oracle, irtc.prm: Triggers will be suppressed by default.
2016-09-01 08:55:27 INFO OGG-01815 Oracle GoldenGate Delivery for Oracle, irtc.prm: Virtual Memory Facilities for: COM
anon alloc: mmap(MAP_ANON) anon free: munmap
file alloc: mmap(MAP_SHARED) file free: munmap
target directories:
/export/home/velikikh/oracle/12.2.0.1/ggs/dirtmp.
2016-09-01 08:55:27 INFO OGG-00996 Oracle GoldenGate Delivery for Oracle, irtc.prm: REPLICAT IRTC started.
2016-09-01 08:55:27 INFO OGG-03522 Oracle GoldenGate Delivery for Oracle, irtc.prm: Setting session time zone to source database time zone 'GMT'.
2016-09-01 08:55:27 INFO OGG-02911 Oracle GoldenGate Capture for Oracle, ietc.prm: Processing table ORCL.TC.DIRECT_LOAD.
2016-09-01 08:55:27 INFO OGG-06495 Oracle GoldenGate Capture for Oracle, ietc.prm: OGG created a session pool with SESSIONPOOLMAX 10, SESSIONPOOLMIN 2 and SESSIONPOOLINCR 2.
2016-09-01 08:55:27 WARNING OGG-02760 Oracle GoldenGate Delivery for Oracle, irtc.prm: ASSUMETARGETDEFS is ignored because trail file contains table definitions.
2016-09-01 08:55:27 INFO OGG-06506 Oracle GoldenGate Delivery for Oracle, irtc.prm: Wildcard MAP resolved (entry orcl.tc.*): Map "ORCL"."TC"."DIRECT_LOAD", target orcl.tc."DIRECT_LOAD".
2016-09-01 08:55:28 WARNING OGG-06439 Oracle GoldenGate Delivery for Oracle, irtc.prm: No unique key is defined for table DIRECT_LOAD. All viable columns will be used to represent the key, but may not guarantee uniqueness. KEYCOLS may be used to define the key.
2016-09-01 08:55:28 INFO OGG-02756 Oracle GoldenGate Delivery for Oracle, irtc.prm: The definition for table ORCL.TC.DIRECT_LOAD is obtained from the trail file.
2016-09-01 08:55:28 INFO OGG-06511 Oracle GoldenGate Delivery for Oracle, irtc.prm: Using following columns in default map by name: COLUMN1, COLUMN2, COLUMN3.
2016-09-01 08:55:28 INFO OGG-06510 Oracle GoldenGate Delivery for Oracle, irtc.prm: Using the following key columns for target table ORCL.TC.DIRECT_LOAD: COLUMN1, COLUMN2, COLUMN3.
2016-09-01 08:55:28 INFO OGG-00178 Oracle GoldenGate Delivery for Oracle, irtc.prm: owner = "TC", table = "DIRECT_LOAD".
2016-09-01 08:55:28 INFO OGG-00991 Oracle GoldenGate Capture for Oracle, ietc.prm: EXTRACT IETC stopped normally.
2016-09-01 08:55:33 INFO OGG-00994 Oracle GoldenGate Delivery for Oracle, irtc.prm: REPLICAT IRTC stopped normally.
Yes, I had a warning like this:
2016-09-01 08:55:12 WARNING OGG-00752 Oracle GoldenGate Capture for Oracle, ietc.prm: Failed to validate table ORCL.TC.DIRECT_LOAD. Likely due to existence of unused column. Please make sure you use sourcedefs in downstream Replicat, or the target table has exactly the same unused columns when using ASSUMETARGETDEFS or DDL replication.
But I obviously didn't violate it as the source and the target table has the same unused columns.
Let's see what has loaded into TARGET database:
Clearly the data from COLUMN2 got loaded into COLUMN3 and I didn't get any errors afterwards leaving my database with "wrong" data.
That's the worst scenario. Originally I faced the issue while I was moving a bunch of data from one database to another using GoldenGate.
The load got ABENDED with ORA-01840 as in my case COLUMN3 had a DATE datatype which may be easily reproduced by the following code:
SQL> select to_date('2', 'yyyy-mm-dd hh24:mi:ss') from dual;
select to_date('2', 'yyyy-mm-dd hh24:mi:ss') from dual
*
ERROR at line 1:
ORA-01840: input value not long enough for date format
Of course, if you are lucky, you may get some other datatype conversion errors. If you are not, you may end with wrong data in your database and it may take a while before you find the problem.
A few words about workarounds.
In this simple scenario, which I have written just for demonstration purposes, it was enough to drop unused columns in TARGET database:
TC@TARGET> alter table direct_load drop unused columns;
Table altered.
