Digging into ADD SCHEMATRANDATA … what is #GoldenGate doing?

In my post on the differences between ADD TRANDATA and ADD SCHEMATRANDATA, I highlighted the differences between the two ways of adding supplemental logging to tables. One of the things I pointed out was that ADD SCHEMATRANDATA doesn’t add any supplemental log groups (SLG). Without SLGs then how does ADD SCHEMATRANDATA work? That was the question I was left with. So I started digging around to find the answer and I think you may be interested in this as well.

Tracing

In order to figure out what is actually going on within the database when ADD SCHEMATRANDATA is run, I had to trace the GoldenGate session. In order to do this, I first had to login to the database from GGSCI using “dblogin useridalias ggate”. After logging in, I had to identify the session and then setup tracing. This was done with the following scripts:

[code language=”css”]—SQL to identify the GGate session
select ‘exec dbms_monitor.session_trace_enable(session_id=>’||sid||’, serial_num=>’||serial#||’, binds=>true, waits=true)’
from v$session where username = ‘GGATE’;
—Start tracing of the session
exec dbms_monitor.session_trace_enable(session_id=>156, serial_num=>15799, binds=>true, waits=>true);
—Disable tracing after done
exec dbms_monitor.session_trace_disable(session_id=>156, serial_num=>15799);[/code]

Now with tracing enabled for the session, I’m able to trace the GoldenGate session from within GGSCI. At this time, I’m able to run DELETE SCHEMATRANDATA and ADD SCHEMATRANDATA against the schema I want to add the logging to.

All the last step of tracing, I need to disable the tracing (script above) of the GoldenGate user and identify the trace file. By default the trace file should be in $ORACLE_BASE/diag/rdbms/<db>/<db>/trace. In this directory, you need to identify the trace files for the session that was traced.

[code language=”css”]oracle >ls -ltr src12c_ora_23267.*
-rw-r—–. 1 oracle oracle 2788 Aug 15 16:09 src12c_ora_23267.trm
-rw-r—–. 1 oracle oracle 300531 Aug 15 16:09 src12c_ora_23267.trc[/code]

After you know the trace file, you can perform a TKPROF on the trace file.

[code language=”css”]
oracle > tkprof src12c_ora_23267.trc src12c_ora_23267.tkprofs
[/code]

This is generate a tkprofs file that will show specifics for the sessions, such as the SQL that is ran. This is what I’m more interested in, what SQL is ran with ADD SCHEMATRANDATA is called.

Quick Review of TKProf file

I’m not going to go into all the details that are in a tkprof generated file, but I took a look through the file trying to figure out what is going on when running the ADD SCHEMATRANDATA. As I was searching the file, I found a reference to LOGMNR$ALWAYS_SUPLOG_COLUMNS.

If you have kept up with the versions of Oracle GoldenGate, you will know that this is a reference to LogMiner and that Oracle is integrating the Oracle GoldenGate processes with it. This is also a hint to where to look, a.k.a Oracle Streams. As I continued to look through the tkprof file, I found a few references to a streams package – DBMS_CAPTURE_ADM; along with sql statements making calls to views like STREAMS$_PREPARE_DDL.

[code language=”css”]BEGIN sys.dbms_capture_adm.PREPARE_SCHEMA_INSTANTIATION(‘soe’,’ALLKEYS_OFF’);
END;
BEGIN sys.dbms_capture_adm.ABORT_SCHEMA_INSTANTIATION(‘soe’); END;[/code]

At this point, it is safe to say, that Oracle is merging Oracle GoldenGate into Oracle Streams.

Review of Packages

Note: These are Oracle packages that are encrypted in the database. You can use UnwrapIt to view if needed. Output here is only for teaching purposes.

Now that I’m armed with what package the ADD SCHEMATRANDATA is calling, I can drill into what exactly is happening.

In taking a look at the DBMS_CAPTURE_ADM package, I wanted to look at the PREPARE_SCHEMA_INSTANTIATION procedure. I can quickly see that the procedure takes the schema_name and that defaults will be used for supplemental logging and container.

[code language=”css”]PROCEDURE PREPARE_SCHEMA_INSTANTIATION(
SCHEMA_NAME IN VARCHAR2,
SUPPLEMENTAL_LOGGING IN VARCHAR2 DEFAULT ‘KEYS’,
CONTAINER IN VARCHAR2 DEFAULT ‘CURRENT’)
IS
BEGIN
DBMS_CAPTURE_ADM_IVK.PREPARE_SCHEMA_INST_IVK(
SCHEMA_NAME => SCHEMA_NAME,
SUPPLEMENTAL_LOGGING => SUPPLEMENTAL_LOGGING,
CONTAINER => CONTAINER);
END;[/code]

After the schema is passed to the procedure, this procedure passes all three of the parameters to another package and procedure for execution. This package is DBMS_CAPTURE_ADM_IVK.PREPARE_SCHEMA_INST_IVK.

[code language=”css”]PROCEDURE PREPARE_SCHEMA_INST_IVK(
SCHEMA_NAME IN VARCHAR2,
SUPPLEMENTAL_LOGGING IN VARCHAR2 DEFAULT ‘KEYS’,
CONTAINER IN VARCHAR2 DEFAULT ‘CURRENT’)
IS
SUPP_LOG_LEVEL BINARY_INTEGER;
SYNCHRONIZATION VARCHAR2(4) := ‘LOCK’;
CANON_CONTAINER DBMS_ID;
BEGIN
DBMS_LOGREP_UTIL.WRITE_TRACE(‘prepare_schema_inst_ivk()+ container: ‘ ||
CONTAINER, DBMS_LOGREP_UTIL.TRACE_FLAG_PUBLISH);
COMMIT;
SUPP_LOG_LEVEL := DBMS_CAPTURE_ADM_IVK.SUPP_LOG_LEVEL_CHECK(SUPPLEMENTAL_LOGGING,
IF DBMS_XSTREAM_GG_ADM.SYNCHRONIZATION IS NOT NULL
THEN
SYNCHRONIZATION := UPPER(DBMS_XSTREAM_GG_ADM.SYNCHRONIZATION);
END IF;
IF (SYNCHRONIZATION != ‘NONE’ AND SYNCHRONIZATION != ‘LOCK’ AND
SYNCHRONIZATION != ‘WAIT’)
THEN
DBMS_LOGREP_UTIL.RAISE_SYSTEM_ERROR(
DBMS_STREAMS_ADM.INVALID_PARAMETER_NUM,
DBMS_LOGREP_UTIL.GET_PROC_USE_CONTEXT, ‘SYNCHRONIZATION’);
END IF;
DBMS_UTILITY.CANONICALIZE(CONTAINER, CANON_CONTAINER, 30);
IF CANON_CONTAINER = ‘CURRENT’
THEN
DBMS_LOGREP_UTIL.WRITE_TRACE(‘prepare schema objects for current’ ||
‘ container: ‘, DBMS_LOGREP_UTIL.TRACE_FLAG_PUBLISH);
DBMS_CAPTURE_ADM_INTERNAL.PREPARE_SCHEMA_INSTANTIATION(
SCHEMA_NAME, SYS_CONTEXT(‘USERENV’,’_USER’), SUPP_LOG_LEVEL,
SYNCHRONIZATION, CANON_CONTAINER);
ELSE
DBMS_CAPTURE_ADM_INTERNAL.PREPARE_SCHEMA_INST_CDB(
SCHEMA_NAME, CANON_CONTAINER,
SYS_CONTEXT(‘USERENV’,’_USER’), SUPP_LOG_LEVEL,
SYNCHRONIZATION);
END IF;
COMMIT;
END;[/code]

In this procedure, you will notice that the input is all three of the parameters that are passed from the PREPARE_SCHEMA_INSTANTIATION procedure. Then this procedure precedes to check the supplemental logging and attempts to sync the tables with the DBMS_XSTREAM_GG_ADM package. After the tables have been synced, then the procedure calls another package and procedure to prepare (DBMS_CAPTURE_ADM_INTERNAL.PREPARE_SCHEMA_INSTANTIATION) the tables with the required supplemental logging level.

When looking at this procedure, it takes in five different parameters; two of which are defaults. After the procedure sets up tracing, it checks to see if the calling procedure is specifying GoldenGate. Once everything is confirmed and synchronization is complete, then the procedure grabs the CURRENT_SCN, waits for any inflight transactions and prepares the schema tables before exiting the package.

[code language=”css”]PROCEDURE PREPARE_SCHEMA_INSTANTIATION(
SCHEMA_NAME IN VARCHAR2,
CANON_INVOKER IN VARCHAR2,
SUPP_LOG_LEVEL IN BINARY_INTEGER,
SYNCHRONIZATION IN VARCHAR2 DEFAULT ‘LOCK’,
CONTAINER IN VARCHAR2 DEFAULT ‘CURRENT’)
IS
CANON_SCHEMA DBMS_ID;
IDX NUMBER :=0;
NAME_ARRAY DBMS_UTILITY.NAME_ARRAY;
OWNER_ARRAY DBMS_UTILITY.NAME_ARRAY;
CURRENT_SCN NUMBER;
WFIT BOOLEAN := FALSE;
RUN_TKLRWT1 BOOLEAN := FALSE;
SUPPLOG BINARY_INTEGER := SUPP_LOG_LEVEL;
TEST_EVENT_LVL BINARY_INTEGER := 0;
BEGIN
DBMS_LOGREP_UTIL.WRITE_TRACE(
‘dbms_capture_adm_internal.prepare_schema_instantiation()+’, DBMS_LOGREP_UTIL.TRACE_FLAG_PUBLISH);
DBMS_LOGREP_UTIL.WRITE_TRACE(‘schema_name=’||SCHEMA_NAME, DBMS_LOGREP_UTIL.TRACE_FLAG_PUBLISH);
DBMS_LOGREP_UTIL.WRITE_TRACE(‘supp_log_level=’||SUPP_LOG_LEVEL, DBMS_LOGREP_UTIL.TRACE_FLAG_PUBLISH);
DBMS_UTILITY.CANONICALIZE(SCHEMA_NAME, CANON_SCHEMA, 30);
IF ((SUPP_LOG_LEVEL = DBMS_STREAMS_DECL.SUPPLOG_ALLKEYS_ON) OR (SUPP_LOG_LEVEL = DBMS_STREAMS_DECL.SUPPLOG_ALLKEYS_OFF))
THEN
STORE_PREPARE_INFO(CANON_SCHEMA, SUPP_LOG_LEVEL);
RETURN;
END IF;
DBMS_LOGREP_UTIL.WRITE_TRACE(‘dbms_capture_adm_internal.prepare_schema_instantiation()+ before read_ev’, DBMS_LOGREP_UTIL.TRACE_FLAG_PUBLISH);
DBMS_SYSTEM.READ_EV(DBMS_LOGREP_UTIL.EXT_TRACE_EV, TEST_EVENT_LVL);
IF (DBMS_XSTREAM_GG_ADM.IS_GOLDENGATE AND TEST_EVENT_LVL = 0)
THEN
SUPPLOG := 0;
END IF;
DBMS_LOGREP_UTIL.WRITE_TRACE(‘dbms_capture_adm_internal.prepare_schema_instantiation()+ before prepare_ddl’,DBMS_LOGREP_UTIL.TRACE_FLAG_PUBLISH);
PREPARE_DDL(CANON_SCHEMA, SUPPLOG);
DBMS_LOGREP_UTIL.WRITE_TRACE(‘dbms_capture_adm_internal.prepare_schema_instantiation()+ before prepare_schema_tables’,DBMS_LOGREP_UTIL.TRACE_FLAG_PUBLISH);
RUN_TKLRWT1 := RUN_WFIT_TEST;
IF (UPPER(SYNCHRONIZATION) = ‘NONE’)
THEN
PREPARE_SCHEMA_TABLES(CANON_SCHEMA, FALSE, CONTAINER);
ELSIF (UPPER(SYNCHRONIZATION) = ‘LOCK’)
THEN
PREPARE_SCHEMA_TABLES(CANON_SCHEMA, TRUE, CONTAINER);
ELSIF (UPPER(SYNCHRONIZATION) = ‘WAIT’)
THEN
WFIT := TRUE;
CURRENT_SCN := DBMS_FLASHBACK.GET_SYSTEM_CHANGE_NUMBER;
DBMS_CAPTURE_ADM_INTERNAL.WAIT_FOR_INFLIGHT_TXN(CURRENT_SCN, ‘Prepare_schema_instantiation’);
PREPARE_SCHEMA_TABLES(CANON_SCHEMA, FALSE, CONTAINER);
END IF;
DONE_WFIT_TEST(WFIT, RUN_TKLRWT1);
END;[/code]

Up to this point, the last three packages have been preparing the tables. Seems like a lot of preparing to get tables set for supplemental logging. Well the last call in the previous package called the procedure to prepare the tables. When I look at this procedure, I see that there is a call to a PREPARE_TABLE_INST procedure (getting a bit lazy on copying the procedure – don’t wan to put to much since this is Oracle’s code).

[code language=”css”]FOR I IN 1..IDX LOOP
BEGIN
DBMS_LOGREP_UTIL.WRITE_TRACE(‘prepare_schema_tables():’ || CANON_OWNER_ARRAY(I) || ‘.’ || CANON_NAME_ARRAY(I), DBMS_LOGREP_UTIL.TRACE_FLAG_PUBLISH);
PREPARE_TABLE_INST(CANON_OWNER_ARRAY(I), CANON_NAME_ARRAY(I),DBMS_STREAMS_DECL.SUPPLOG_NONE, LOCKING, CONTAINER);
EXCEPTION WHEN OTHERS THEN
DBMS_LOGREP_UTIL.DUMP_TRACE(‘error:dbms_capture_adm_internal.prepare_table_inst(‘||’owner=’||CANON_OWNER_ARRAY(I)||’ name=’||CANON_NAME_ARRAY(I));
END;[/code]

Now, when I go an look at the PREPARE_TABLE_INST procedure, I see that the procedure is calling a C package called “knlcpreptabinst” to set the supplemental logging on the tables associated with the schema.

[code language=”css”]PROCEDURE PREPARE_TABLE_INST(
CANON_OWNER IN VARCHAR2,
CANON_TABLE_NAME IN VARCHAR2,
SUPPLEMENTAL_LOGGING_LEVEL IN BINARY_INTEGER,
LOCKING IN BOOLEAN,
CONTAINER IN VARCHAR2)
IS
EXTERNAL
NAME “knlcpreptabinst”
LIBRARY DBMS_LOGREP_LIB
WITH CONTEXT
PARAMETERS(CONTEXT,
CANON_OWNER OCISTRING, CANON_OWNER INDICATOR SB2,
CANON_TABLE_NAME OCISTRING, CANON_TABLE_NAME INDICATOR SB2,
SUPPLEMENTAL_LOGGING_LEVEL UB4,
LOCKING UB2, LOCKING INDICATOR SB2,
CONTAINER OCISTRING, CONTAINER INDICATOR SB2)
LANGUAGE C;[/code]

Without drilling down into the C package, I cannot see exactly how the supplemental logging is added or where it is exactly stored in the database. I can only assume (we know what that means … lol), that it is in the data dictionary some where.

Looking for tables or views that may shed some light on this as well, I’ve found LOGMNR$SCHEMA_ALLKEY_SUPLOG that will show you the schema, if all keys are in supplemental log mode and if no validated pks are allowed. The following query is what I used to extract information about the SOE schema:

[code language=”css”]
select * from LOGMNR$SCHEMA_ALLKEY_SUPLOG
where allkey_suplog = ‘YES’;
[/code]

Output is as follows:

[code language=”css”]
SCHEMA_NAME ALL ALL
————— — —
SOE YES NO[/code]

In drilling down further, after have a friend of mine pointed out a function to me (follow him on twitter -> @resetlogs). You can get down to the table level on supplemental logging when using ADD SCHEMATRANDATA. There is a log miner function that has to be called when using SQL to pull the correct information. This function is similar named to the table I referenced above … LOGMNR$ALWAYS_SUPLOG_COLUMNS.

This function takes two parameters. The first is the schema that holds the objects and the second is the table name. So in the following example, I can see that the ORDERS table of the SOE schema has supplemental logging added.

[code language=”css”]select * from table(logmnr$always_suplog_columns(‘SOE’,’ORDERS’));
OWNER TABLE_NAME COLUMN_NAME INTCOL SEGCOL USERCOL
————— —————————— —————————— ———- ———- ———-
SOE ORDERS ORDER_ID 1 1 1
SOE ORDERS ORDER_TOTAL 6 6 6
SOE ORDERS COST_OF_DELIVERY 11 11 11
SOE ORDERS DELIVERY_ADDRESS_ID 13 13 13
SOE ORDERS ORDER_DATE 2 2 2
SOE ORDERS CUSTOMER_CLASS 14 14 14
SOE ORDERS CUSTOMER_ID 4 4 4
SOE ORDERS ORDER_STATUS 5 5 5
SOE ORDERS PROMOTION_ID 8 8 8
SOE ORDERS ORDER_MODE 3 3 3
SOE ORDERS SALES_REP_ID 7 7 7
SOE ORDERS WAREHOUSE_ID 9 9 9
SOE ORDERS DELIVERY_TYPE 10 10 10
SOE ORDERS WAIT_TILL_ALL_AVAILABLE 12 12 12
SOE ORDERS CARD_ID 15 15 15
SOE ORDERS INVOICE_ADDRESS_ID 16 16 16
[/code]

I know this has been a long post, but hopefully, I’ve been able to somewhat show how the ADD SCHEMATRANDATA command within GGSCI works and where you can see if supplemental logging is turned on for the selected schema. As I was trying to dig to the root of this issue, I found it interesting that so many packages are involved with setting the supplemental logging on a schema/tables; while identifying if it is enabled is not as easy as ADD TRANDATA. Where when you use ADD TRANDATA the tables are easily identified and can quickly see that the supplemental log groups have been added.

As Oracle GoldenGate for Oracle moves to a more integrated approach to replication, I think more items will be tied to the log miner and streams architecture.

Enjoy!!

@dbasolved
http://about.me/dbasolved

Please follow and like: